1 2 Previous Next 16 Replies Latest reply on Nov 19, 2010 4:36 PM by ngoodman310

    JBoss Problem with Sun 64-bit JVM

    ngoodman310

      I have a Java 6 enterprise application that can be run in either JBoss (jboss-6.0.0.20100721-M4) or WebLogic (10.1).  When doing certain large retrieves (16,000 deep objects) using EclipseLink, JBoss, running via the Sun 64 bit JVM, crashes with a GC error (98% of time doing less than 2% of work).  What's odd, however, is that the same code works when running JBoss with the JRockit 64 bit or the Sun 32 bit JVM; moreover, with the same memory settings, the same code works on WebLogic with any of the JRockit 64 bit, Sun 32 bit, or Sun 64 bit JVM.  I would have thought that the error would be specific to the JVM and not the application server.

       

      We have played with the memory arguments to give JBoss on Sun 64 more memory, but that doesn't make any difference (even going to 4 GB of RAM for new generation still crashes).  We have also enabled the GC VM args but have not learned anything from the output during the crashes (they are 100% reproducible).  We have reproduced this on Windows Server 2003 (64 Bit) and Windows 7 (64 bit).

       

      My questions are:

       

      1) Is there some setting within JBoss that could be effecting the new generation memory space (i.e., causing it to ignore the VM settings)?

       

      2) Is the 64-bit Sun JVM widely used for application servers (our current production version has used the JRockit 64 bit VM for several years without issue, but the Sun 64 JVM beats it in several of our benchmarks).

       

       

       

      thanks,

        Nick

        • 1. Re: JBoss Problem with Sun 64-bit JVM
          smarlow

          What is the full GC error message?

          • 2. Re: JBoss Problem with Sun 64-bit JVM
            ngoodman310

            The stack trace is:

             

            java.lang.OutOfMemoryError: GC overhead limit exceeded
                    at org.eclipse.persistence.internal.descriptors.MethodAttributeAccessor.setAttributeValueInObject(MethodAttributeAccessor.java:177)
                    at org.eclipse.persistence.mappings.DatabaseMapping.setAttributeValueInObject(DatabaseMapping.java:1246)
                    at org.eclipse.persistence.mappings.DatabaseMapping.readFromRowIntoObject(DatabaseMapping.java:1137)
                    at org.eclipse.persistence.internal.descriptors.ObjectBuilder.buildAttributesIntoObject(ObjectBuilder.java:325)
                    at org.eclipse.persistence.internal.descriptors.ObjectBuilder.buildObject(ObjectBuilder.java:652)
                    at org.eclipse.persistence.internal.descriptors.ObjectBuilder.buildObject(ObjectBuilder.java:487)
                    at org.eclipse.persistence.internal.descriptors.ObjectBuilder.buildObjectsInto(ObjectBuilder.java:824)
                    at org.eclipse.persistence.queries.ReadAllQuery.executeObjectLevelReadQuery(ReadAllQuery.java:493)
                    at org.eclipse.persistence.queries.ObjectLevelReadQuery.executeDatabaseQuery(ObjectLevelReadQuery.java:928)
                    at org.eclipse.persistence.queries.DatabaseQuery.execute(DatabaseQuery.java:664)
                    at org.eclipse.persistence.queries.ObjectLevelReadQuery.execute(ObjectLevelReadQuery.java:889)
                    at org.eclipse.persistence.queries.ReadAllQuery.execute(ReadAllQuery.java:458)
                    at org.eclipse.persistence.internal.sessions.AbstractSession.internalExecuteQuery(AbstractSession.java:2243)
                    at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1181)
                    at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1165)
                    at org.eclipse.persistence.internal.sessions.AbstractSession.executeQuery(AbstractSession.java:1125)
                    at com.rbs.core.server.persistence.RBSTLBaseDAO.getObjects(RBSTLBaseDAO.java:2090)
                    at com.rbs.core.server.persistence.RBSTLBaseDAO.getObjects(RBSTLBaseDAO.java:2041)
                    at com.rbs.core.server.persistence.RBSTLBaseDAO.getObjectsFromDatabase(RBSTLBaseDAO.java:1872)
                    at com.rbs.core.server.persistence.RBSTLBaseDAO.getObjects(RBSTLBaseDAO.java:2027)
                    at com.rbs.business.agreement.server.persistence.AgreementDAO.getBillableContracts(AgreementDAO.java:2588)
                    at com.rbs.business.agreement.server.ejb.AgreementManagerEJB.getBillableContracts(AgreementManagerEJB.java:1940)
                    at com.rbs.business.agreement.server.ejb.AgreementManagerEJB.getBillableContracts(AgreementManagerEJB.java:1928)
                    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
                    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
                    at java.lang.reflect.Method.invoke(Method.java:597)
                    at org.jboss.invocation.Invocation.performCall(Invocation.java:386)
                    at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:233)
                    at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:156)
                    at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:173)
                    at org.jboss.ejb.plugins.CallValidationInterceptor.invoke(CallValidationInterceptor.java:63)

                    at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:237) [:6.0.0.20100721-M4]
                    ... 148 more

             

             

             

            The output when I add "-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps" to the Java options:

            227.905: [Full GC[Unloading class org.python.pycode._pyx14]
            [Unloading class org.python.pycode._pyx25]
            [Unloading class org.python.pycode._pyx32]
            [Unloading class org.python.pycode._pyx11]
            [Unloading class org.python.pycode._pyx10]
            [Unloading class org.python.pycode._pyx4]
            [Unloading class sun.reflect.GeneratedConstructorAccessor99]
            [Unloading class org.python.pycode._pyx17]
            [Unloading class org.python.pycode._pyx6]
            [Unloading class sun.reflect.GeneratedConstructorAccessor105]
            [Unloading class org.python.pycode._pyx31]
            [Unloading class org.python.pycode._pyx18]
            [Unloading class org.python.pycode._pyx15]
            [Unloading class org.python.pycode._pyx29]
            [Unloading class org.python.pycode._pyx5]
            [Unloading class org.python.pycode._pyx23]
            [Unloading class sun.reflect.GeneratedConstructorAccessor109]
            [Unloading class org.python.pycode._pyx28]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor36]
            [Unloading class org.python.pycode._pyx16]
            [Unloading class org.python.pycode._pyx24]
            [Unloading class org.python.pycode._pyx30]
            [Unloading class org.python.pycode._pyx13]
            [Unloading class org.python.pycode._pyx19]
            [Unloading class org.python.pycode._pyx9]
            [Unloading class org.python.pycode._pyx8]
            [Unloading class org.python.pycode._pyx21]
            [Unloading class org.python.pycode._pyx7]
            [Unloading class org.python.pycode._pyx27]
            [Unloading class org.python.pycode._pyx12]
            [Unloading class org.python.pycode._pyx22]
            [Unloading class org.python.pycode._pyx26]
            [Unloading class org.python.pycode._pyx20]
            [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 336910K->339691K(349568K)] 395150K->339691K(466048K) [PSPermGen: 128613K->128317K(149120K)], 1.8820019 secs] [Times: user=1.59 sys=0.00, real=1.89 secs]
            230.034: [Full GC[Unloading class sun.reflect.GeneratedConstructorAccessor59]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor87]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor88]
            [Unloading class sun.reflect.GeneratedMethodAccessor297]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor63]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor76]
            [Unloading class sun.reflect.GeneratedConstructorAccessor5]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor58]
            [Unloading class sun.reflect.GeneratedConstructorAccessor39]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor106]
            [Unloading class sun.reflect.GeneratedConstructorAccessor113]
            [Unloading class sun.reflect.GeneratedConstructorAccessor149]
            [Unloading class sun.reflect.GeneratedConstructorAccessor111]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor53]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor68]
            [Unloading class sun.reflect.GeneratedConstructorAccessor130]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor85]
            [Unloading class sun.reflect.GeneratedMethodAccessor285]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor81]
            [Unloading class sun.reflect.GeneratedConstructorAccessor150]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor71]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor95]
            [Unloading class sun.reflect.GeneratedMethodAccessor282]
            [Unloading class sun.reflect.GeneratedConstructorAccessor121]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor80]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor79]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor60]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor47]
            [Unloading class sun.reflect.GeneratedConstructorAccessor46]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor74]
            [Unloading class sun.reflect.GeneratedMethodAccessor283]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor59]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor78]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor72]
            [Unloading class sun.reflect.GeneratedMethodAccessor281]
            [Unloading class sun.reflect.GeneratedConstructorAccessor116]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor82]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor62]
            [Unloading class sun.reflect.GeneratedConstructorAccessor112]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor66]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor54]
            [Unloading class sun.reflect.GeneratedConstructorAccessor8]
            [Unloading class sun.reflect.GeneratedConstructorAccessor110]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor45]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor75]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor50]
            [Unloading class sun.reflect.GeneratedConstructorAccessor98]
            [Unloading class sun.reflect.GeneratedConstructorAccessor2]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor92]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor55]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor67]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor65]
            [Unloading class sun.reflect.GeneratedConstructorAccessor40]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor105]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor56]
            [Unloading class sun.reflect.GeneratedMethodAccessor292]
            [Unloading class sun.reflect.GeneratedMethodAccessor284]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor89]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor64]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor84]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor57]
            [Unloading class sun.reflect.GeneratedConstructorAccessor1]
            [Unloading class sun.reflect.GeneratedMethodAccessor289]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor86]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor90]
            [Unloading class sun.reflect.GeneratedMethodAccessor298]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor44]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor73]
            [Unloading class sun.reflect.GeneratedConstructorAccessor120]
            [Unloading class sun.reflect.GeneratedMethodAccessor291]
            [Unloading class sun.reflect.GeneratedConstructorAccessor4]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor70]
            [Unloading class sun.reflect.GeneratedMethodAccessor319]
            [Unloading class sun.reflect.GeneratedConstructorAccessor122]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor104]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor91]
            [Unloading class sun.reflect.GeneratedMethodAccessor286]
            [Unloading class sun.reflect.GeneratedMethodAccessor287]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor93]
            [Unloading class sun.reflect.GeneratedMethodAccessor288]
            [Unloading class sun.reflect.GeneratedConstructorAccessor117]
            [Unloading class sun.reflect.GeneratedMethodAccessor299]
            [Unloading class sun.reflect.GeneratedConstructorAccessor119]
            [Unloading class sun.reflect.GeneratedConstructorAccessor142]
            [Unloading class sun.reflect.GeneratedConstructorAccessor14]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor61]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor77]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor43]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor83]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor69]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor94]
            [Unloading class sun.reflect.GeneratedMethodAccessor290]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor46]
            [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 339691K->340574K(349568K)] 397931K->340574K(466048K) [PSPermGen: 128351K->128351K(146432K)], 1.6015632 secs] [Times: user=1.11 sys=0.00, real=1.60 secs]
            231.803: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 340574K->341399K(349568K)] 398814K->341399K(466048K) [PSPermGen: 128352K->128352K(144192K)], 1.1222386 secs] [Times: user=1.11 sys=0.00, real=1.12 secs]
            233.062: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 341399K->342269K(349568K)] 399639K->342269K(466048K) [PSPermGen: 128352K->128352K(141504K)], 1.1125574 secs] [Times: user=1.09 sys=0.00, real=1.11 secs]
            234.258: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 342269K->336606K(349568K)] 400509K->336606K(466048K) [PSPermGen: 128353K->127679K(138880K)], 1.3611939 secs] [Times: user=1.34 sys=0.00, real=1.37 secs]
            235.683: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 336606K->337492K(349568K)] 394846K->337492K(466048K) [PSPermGen: 127679K->127679K(137216K)], 1.1134949 secs] [Times: user=1.06 sys=0.00, real=1.11 secs]
            236.893: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 337492K->338343K(349568K)] 395732K->338343K(466048K) [PSPermGen: 127680K->127680K(136000K)], 1.1426769 secs] [Times: user=0.89 sys=0.02, real=1.14 secs]
            238.095: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 338343K->339213K(349568K)] 396583K->339213K(466048K) [PSPermGen: 127680K->127680K(134784K)], 1.1106031 secs] [Times: user=1.11 sys=0.00, real=1.11 secs]
            239.266: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 339213K->339650K(349568K)] 397453K->339650K(466048K) [PSPermGen: 127680K->127680K(133696K)], 1.1375907 secs] [Times: user=1.12 sys=0.00, real=1.14 secs]
            240.461: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 339650K->340558K(349568K)] 397890K->340558K(466048K) [PSPermGen: 127682K->127682K(133056K)], 1.1131609 secs] [Times: user=1.08 sys=0.00, real=1.11 secs]
            241.635: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 340558K->341425K(349568K)] 398798K->341425K(466048K) [PSPermGen: 127686K->127686K(132032K)], 1.0935576 secs] [Times: user=1.09 sys=0.00, real=1.09 secs]
            242.790: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 341425K->342276K(349568K)] 399665K->342276K(466048K) [PSPermGen: 127689K->127689K(131328K)], 1.1266147 secs] [Times: user=1.11 sys=0.00, real=1.13 secs]
            243.976: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 342276K->342672K(349568K)] 400516K->342672K(466048K) [PSPermGen: 127689K->127689K(130816K)], 1.2618752 secs] [Times: user=1.23 sys=0.00, real=1.26 secs]
            245.309: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 342672K->343544K(349568K)] 400912K->343544K(466048K) [PSPermGen: 127690K->127690K(130304K)], 1.1592463 secs] [Times: user=1.12 sys=0.00, real=1.16 secs]
            246.529: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 343544K->344419K(349568K)] 401784K->344419K(466048K) [PSPermGen: 127690K->127690K(129664K)], 1.2048330 secs] [Times: user=1.17 sys=0.00, real=1.21 secs]
            247.803: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 344419K->345276K(349568K)] 402659K->345276K(466048K) [PSPermGen: 127690K->127690K(129600K)], 1.1454268 secs] [Times: user=1.14 sys=0.00, real=1.15 secs]
            249.002: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 345276K->345707K(349568K)] 403516K->345707K(466048K) [PSPermGen: 127690K->127690K(129088K)], 1.2194049 secs] [Times: user=1.22 sys=0.00, real=1.22 secs]
            250.275: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 345707K->346662K(349568K)] 403947K->346662K(466048K) [PSPermGen: 127690K->127690K(129088K)], 1.0972566 secs] [Times: user=1.09 sys=0.00, real=1.10 secs]
            251.424: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 346662K->347531K(349568K)] 404902K->347531K(466048K) [PSPermGen: 127690K->127690K(128896K)], 1.0893530 secs] [Times: user=1.09 sys=0.00, real=1.09 secs]
            252.566: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 347531K->348405K(349568K)] 405771K->348405K(466048K) [PSPermGen: 127690K->127690K(128768K)], 1.0823044 secs] [Times: user=1.08 sys=0.00, real=1.08 secs]
            253.709: [Full GC[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor30]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor107]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor113]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor115]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor112]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor26]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor31]
            [Unloading class sun.reflect.GeneratedConstructorAccessor104]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor32]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor114]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor108]
            [Unloading class sun.reflect.GeneratedConstructorAccessor107]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor116]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor29]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor110]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor111]
            [Unloading class sun.reflect.GeneratedConstructorAccessor106]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor109]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor27]
            [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 348405K->348543K(349568K)] 406645K->348543K(466048K) [PSPermGen: 127693K->127617K(128768K)], 1.4271525 secs] [Times: user=1.09 sys=0.01, real=1.43 secs]
            255.183: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 348543K->349424K(349568K)] 406783K->349424K(466048K) [PSPermGen: 127617K->127617K(128192K)], 1.1001925 secs] [Times: user=0.94 sys=0.02, real=1.10 secs]
            256.329: [Full GC [PSYoungGen: 58240K->724K(116480K)] [PSOldGen: 349424K->349567K(349568K)] 407664K->350292K(466048K) [PSPermGen: 127617K->127617K(128064K)], 1.1003965 secs] [Times: user=1.09 sys=0.00, real=1.10 secs]
            257.474: [Full GC [PSYoungGen: 58240K->4485K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->354053K(466048K) [PSPermGen: 127617K->127617K(128000K)], 1.0946474 secs] [Times: user=1.09 sys=0.00, real=1.10 secs]
            258.610: [Full GC [PSYoungGen: 58240K->1932K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->351500K(466048K) [PSPermGen: 127617K->127617K(128192K)], 1.1083831 secs] [Times: user=1.11 sys=0.00, real=1.11 secs]
            259.762: [Full GC [PSYoungGen: 58240K->5661K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->355229K(466048K) [PSPermGen: 127617K->127617K(128128K)], 1.0973558 secs] [Times: user=1.09 sys=0.00, real=1.10 secs]
            260.899: [Full GC [PSYoungGen: 58240K->6449K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->356017K(466048K) [PSPermGen: 127617K->127617K(128128K)], 1.0979846 secs] [Times: user=1.08 sys=0.00, real=1.10 secs]
            262.035: [Full GC [PSYoungGen: 58240K->7218K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->356786K(466048K) [PSPermGen: 127617K->127617K(128064K)], 1.1005052 secs] [Times: user=1.09 sys=0.00, real=1.10 secs]
            263.173: [Full GC [PSYoungGen: 58240K->4698K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->354266K(466048K) [PSPermGen: 127617K->127617K(128064K)], 1.1137028 secs] [Times: user=1.11 sys=0.00, real=1.12 secs]
            264.325: [Full GC [PSYoungGen: 58240K->8406K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->357974K(466048K) [PSPermGen: 127617K->127617K(128000K)], 1.0998255 secs] [Times: user=1.09 sys=0.00, real=1.10 secs]
            265.460: [Full GC[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor121]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor120]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor119]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor123]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor122]
            [PSYoungGen: 58240K->9129K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->358697K(466048K) [PSPermGen: 127617K->127617K(128000K)], 1.1189040 secs] [Times: user=1.11 sys=0.00, real=1.12 secs]
            266.613: [Full GC [PSYoungGen: 58240K->9862K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->359430K(466048K) [PSPermGen: 127617K->127617K(128000K)], 1.1066213 secs] [Times: user=1.09 sys=0.00, real=1.11 secs]
            267.755: [Full GC [PSYoungGen: 58240K->7094K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->356662K(466048K) [PSPermGen: 127617K->127596K(127936K)], 1.3974736 secs] [Times: user=1.34 sys=0.00, real=1.40 secs]
            269.188: [Full GC [PSYoungGen: 58240K->10765K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->360333K(466048K) [PSPermGen: 127596K->127596K(127936K)], 1.1188416 secs] [Times: user=1.09 sys=0.02, real=1.12 secs]
            270.339: [Full GC [PSYoungGen: 58240K->11638K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->361206K(466048K) [PSPermGen: 127596K->127596K(127936K)], 1.1066119 secs] [Times: user=1.11 sys=0.00, real=1.11 secs]
            271.480: [Full GC [PSYoungGen: 58240K->12311K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->361879K(466048K) [PSPermGen: 127596K->127596K(127936K)], 1.1063523 secs] [Times: user=0.89 sys=0.01, real=1.11 secs]
            272.620: [Full GC [PSYoungGen: 58240K->9675K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->359243K(466048K) [PSPermGen: 127596K->127596K(127936K)], 1.1427676 secs] [Times: user=1.06 sys=0.00, real=1.14 secs]
            273.797: [Full GC [PSYoungGen: 58240K->13301K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->362869K(466048K) [PSPermGen: 127596K->127596K(127936K)], 1.1452629 secs] [Times: user=1.12 sys=0.00, real=1.14 secs]
            274.972: [Full GC [PSYoungGen: 58240K->13974K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->363542K(466048K) [PSPermGen: 127596K->127596K(127872K)], 1.1436106 secs] [Times: user=1.14 sys=0.00, real=1.14 secs]
            276.144: [Full GC [PSYoungGen: 58240K->14679K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->364247K(466048K) [PSPermGen: 127596K->127596K(127872K)], 1.1166781 secs] [Times: user=1.05 sys=0.00, real=1.12 secs]
            277.293: [Full GC [PSYoungGen: 58240K->12071K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->361639K(466048K) [PSPermGen: 127596K->127596K(127872K)], 1.1509137 secs] [Times: user=1.14 sys=0.00, real=1.15 secs]
            278.473: [Full GC [PSYoungGen: 58240K->15646K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->365214K(466048K) [PSPermGen: 127596K->127596K(127872K)], 1.1432017 secs] [Times: user=1.11 sys=0.00, real=1.14 secs]
            279.655: [Full GC [PSYoungGen: 58240K->16688K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->366256K(466048K) [PSPermGen: 127596K->127596K(127872K)], 1.2623226 secs] [Times: user=1.23 sys=0.00, real=1.26 secs]
            280.947: [Full GC [PSYoungGen: 58240K->17220K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->366788K(466048K) [PSPermGen: 127596K->127596K(127872K)], 1.1811021 secs] [Times: user=1.17 sys=0.00, real=1.18 secs]
            282.154: [Full GC [PSYoungGen: 58240K->14600K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->364168K(466048K) [PSPermGen: 127596K->127596K(127872K)], 1.3125267 secs] [Times: user=1.30 sys=0.00, real=1.31 secs]
            283.499: [Full GC [PSYoungGen: 58240K->18025K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->367593K(466048K) [PSPermGen: 127596K->127596K(127872K)], 1.1995232 secs] [Times: user=1.20 sys=0.00, real=1.21 secs]
            284.731: [Full GC [PSYoungGen: 58240K->18536K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->368104K(466048K) [PSPermGen: 127596K->127596K(127872K)], 1.2352250 secs] [Times: user=1.22 sys=0.00, real=1.24 secs]
            285.992: [Full GC [PSYoungGen: 58240K->19056K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->368624K(466048K) [PSPermGen: 127596K->127596K(127872K)], 1.1356570 secs] [Times: user=1.12 sys=0.00, real=1.14 secs]
            287.154: [Full GC [PSYoungGen: 58240K->16424K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->365992K(466048K) [PSPermGen: 127597K->127597K(127872K)], 1.2125146 secs] [Times: user=1.22 sys=0.00, real=1.21 secs]
            288.411: [Full GC [PSYoungGen: 58240K->19938K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->369506K(466048K) [PSPermGen: 127597K->127597K(127872K)], 1.1198057 secs] [Times: user=1.08 sys=0.00, real=1.12 secs]
            289.605: [Full GC [PSYoungGen: 58240K->20419K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->369987K(466048K) [PSPermGen: 127597K->127597K(127872K)], 1.1664138 secs] [Times: user=1.00 sys=0.00, real=1.17 secs]
            290.801: [Full GC [PSYoungGen: 58240K->20932K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->370500K(466048K) [PSPermGen: 127597K->127597K(127872K)], 1.2073425 secs] [Times: user=1.17 sys=0.00, real=1.21 secs]
            292.030: [Full GC [PSYoungGen: 58240K->18325K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->367893K(466048K) [PSPermGen: 127597K->127597K(127872K)], 1.3965882 secs] [Times: user=1.39 sys=0.00, real=1.40 secs]
            293.452: [Full GC [PSYoungGen: 58240K->21809K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->371377K(466048K) [PSPermGen: 127597K->127597K(127872K)], 1.2772513 secs] [Times: user=1.28 sys=0.00, real=1.28 secs]
            294.761: [Full GC [PSYoungGen: 58240K->22324K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->371892K(466048K) [PSPermGen: 127597K->127597K(127872K)], 1.2558634 secs] [Times: user=1.23 sys=0.00, real=1.26 secs]
            296.042: [Full GC [PSYoungGen: 58240K->22852K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->372420K(466048K) [PSPermGen: 127597K->127597K(127872K)], 1.2562642 secs] [Times: user=1.19 sys=0.00, real=1.26 secs]
            297.325: [Full GC [PSYoungGen: 58240K->20210K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->369778K(466048K) [PSPermGen: 127597K->127597K(127872K)], 1.3535704 secs] [Times: user=1.31 sys=0.00, real=1.35 secs]
            298.704: [Full GC [PSYoungGen: 58240K->23673K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->373241K(466048K) [PSPermGen: 127597K->127597K(127872K)], 1.3592926 secs] [Times: user=1.36 sys=0.00, real=1.36 secs]
            300.096: [Full GC [PSYoungGen: 58240K->24148K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->373715K(466048K) [PSPermGen: 127598K->127598K(127872K)], 1.2693374 secs] [Times: user=1.26 sys=0.00, real=1.27 secs]
            301.393: [Full GC [PSYoungGen: 58240K->24644K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->374212K(466048K) [PSPermGen: 127598K->127598K(127872K)], 1.2593499 secs] [Times: user=1.26 sys=0.00, real=1.26 secs]
            302.675: [Full GC [PSYoungGen: 58240K->21991K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->371559K(466048K) [PSPermGen: 127599K->127599K(127872K)], 1.3501067 secs] [Times: user=1.34 sys=0.00, real=1.35 secs]
            304.044: [Full GC [PSYoungGen: 58240K->25419K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->374987K(466048K) [PSPermGen: 127599K->127599K(127872K)], 1.1504436 secs] [Times: user=1.15 sys=0.00, real=1.15 secs]
            305.215: [Full GC [PSYoungGen: 58240K->25880K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->375448K(466048K) [PSPermGen: 127599K->127599K(127872K)], 1.1589264 secs] [Times: user=1.14 sys=0.00, real=1.16 secs]
            306.397: [Full GC [PSYoungGen: 58240K->26353K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->375921K(466048K) [PSPermGen: 127599K->127599K(127872K)], 1.1231736 secs] [Times: user=0.89 sys=0.00, real=1.12 secs]
            307.537: [Full GC [PSYoungGen: 58240K->23686K(116480K)] [PSOldGen: 349567K->349568K(349568K)] 407807K->373254K(466048K) [PSPermGen: 127599K->127599K(127872K)], 1.1620219 secs] [Times: user=1.03 sys=0.00, real=1.16 secs]
            308.975: [Full GC [PSYoungGen: 58240K->38710K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->388278K(466048K) [PSPermGen: 127656K->127656K(128000K)], 1.2048138 secs] [Times: user=1.19 sys=0.00, real=1.21 secs]
            310.351: [Full GC [PSYoungGen: 58240K->50938K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->400506K(466048K) [PSPermGen: 127670K->127670K(128000K)], 1.2540712 secs] [Times: user=1.25 sys=0.00, real=1.26 secs]
            311.669: [Full GC [PSYoungGen: 58240K->55329K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->404897K(466048K) [PSPermGen: 127670K->127670K(128000K)], 1.2585936 secs] [Times: user=1.20 sys=0.00, real=1.26 secs]
            312.943: [Full GC[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor124]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor125]
            [PSYoungGen: 58240K->54199K(116480K)] [PSOldGen: 349568K->349567K(349568K)] 407808K->403767K(466048K) [PSPermGen: 127670K->127660K(128000K)], 1.5733274 secs] [Times: user=1.53 sys=0.00, real=1.57 secs]
            314.542: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127660K->127660K(128000K)], 1.2803335 secs] [Times: user=1.26 sys=0.00, real=1.28 secs]
            315.825: [Full GC[Unloading class sun.reflect.GeneratedSerializationConstructorAccessor42]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor37]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor97]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor49]
            [Unloading class sun.reflect.GeneratedConstructorAccessor140]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor48]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor103]
            [Unloading class sun.reflect.GeneratedMethodAccessor337]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor23]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor99]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor98]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor22]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor14]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor132]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor41]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor129]
            [Unloading class sun.reflect.GeneratedConstructorAccessor141]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor21]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor102]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor134]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor3]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor35]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor96]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor128]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor20]
            [Unloading class sun.reflect.GeneratedMethodAccessor336]
            [Unloading class sun.reflect.GeneratedMethodAccessor341]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor137]
            [Unloading class sun.reflect.GeneratedMethodAccessor332]
            [Unloading class sun.reflect.GeneratedMethodAccessor340]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor101]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor51]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor126]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor52]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor141]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor38]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor136]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor127]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor138]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor139]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor130]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor133]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor4]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor140]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor1]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor6]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor100]
            [Unloading class sun.reflect.GeneratedConstructorAccessor168]
            [Unloading class sun.reflect.GeneratedMethodAccessor321]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor135]
            [Unloading class sun.reflect.GeneratedMethodAccessor327]
            [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor131]
            [PSYoungGen: 58240K->56283K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->405851K(466048K) [PSPermGen: 127660K->127450K(127488K)], 1.8554693 secs] [Times: user=1.55 sys=0.00, real=1.86 secs]
            317.712: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127450K->127450K(127488K)], 1.2581407 secs] [Times: user=1.25 sys=0.00, real=1.26 secs]
            318.971: [Full GC [PSYoungGen: 58240K->56600K(116480K)] [PSOldGen: 349567K->349568K(349568K)] 407807K->406168K(466048K) [PSPermGen: 127450K->127450K(127488K)], 1.3174267 secs] [Times: user=1.30 sys=0.00, real=1.32 secs]
            320.298: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->407808K(466048K) [PSPermGen: 127450K->127450K(127488K)], 1.2762012 secs] [Times: user=1.26 sys=0.00, real=1.28 secs]
            321.575: [Full GC [PSYoungGen: 58240K->57613K(116480K)] [PSOldGen: 349568K->349567K(349568K)] 407808K->407181K(466048K) [PSPermGen: 127450K->127450K(127488K)], 1.3293998 secs] [Times: user=1.33 sys=0.00, real=1.33 secs]
            322.916: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127450K->127450K(127488K)], 1.3261597 secs] [Times: user=1.33 sys=0.00, real=1.33 secs]
            324.243: [Full GC [PSYoungGen: 58240K->57778K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407346K(466048K) [PSPermGen: 127450K->127450K(127488K)], 1.2585966 secs] [Times: user=1.00 sys=0.00, real=1.26 secs]
            325.510: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127450K->127450K(127488K)], 1.2623564 secs] [Times: user=1.26 sys=0.00, real=1.26 secs]
            326.777: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->407808K(466048K) [PSPermGen: 127450K->127450K(127488K)], 1.2407586 secs] [Times: user=1.22 sys=0.00, real=1.24 secs]
            328.019: [Full GC [PSYoungGen: 58240K->57777K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->407345K(466048K) [PSPermGen: 127450K->127450K(127488K)], 1.2429926 secs] [Times: user=1.19 sys=0.00, real=1.24 secs]
            329.269: [Full GC [PSYoungGen: 58240K->57881K(116480K)] [PSOldGen: 349568K->349567K(349568K)] 407808K->407449K(466048K) [PSPermGen: 127450K->127450K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3031191 secs] [Times: user=1.26 sys=0.00, real=1.30 secs]
            330.584: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127450K->127450K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.4227516 secs] [Times: user=1.39 sys=0.00, real=1.42 secs]
            332.010: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->407808K(466048K) [PSPermGen: 127450K->127450K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3171077 secs] [Times: user=1.28 sys=0.00, real=1.32 secs]
            333.334: [Full GC [PSYoungGen: 58240K->58073K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->407641K(466048K) [PSPermGen: 127450K->127450K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2723974 secs] [Times: user=1.25 sys=0.00, real=1.28 secs]
            334.616: [Full GC [PSYoungGen: 58240K->58075K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->407643K(466048K) [PSPermGen: 127450K->127450K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3196625 secs] [Times: user=1.31 sys=0.00, real=1.32 secs]
            335.943: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->407808K(466048K) [PSPermGen: 127450K->127450K(127488K)]      GC time is exceeding GCTimeLimit of 98%
            , 1.2772872 secs] [Times: user=1.26 sys=0.00, real=1.28 secs]
            337.230: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->407808K(466048K) [PSPermGen: 127450K->127450K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3077540 secs] [Times: user=1.31 sys=0.00, real=1.31 secs]
            338.539: [Full GC [PSYoungGen: 58240K->58074K(116480K)] [PSOldGen: 349568K->349567K(349568K)] 407808K->407642K(466048K) [PSPermGen: 127450K->127450K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.4469222 secs] [Times: user=1.44 sys=0.00, real=1.45 secs]
            340.008: [Full GC [PSYoungGen: 58240K->58114K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407682K(466048K) [PSPermGen: 127450K->127450K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.4415906 secs] [Times: user=1.40 sys=0.00, real=1.44 secs]
            341.454: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127452K->127452K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2188095 secs] [Times: user=0.97 sys=0.00, real=1.22 secs]
            342.678: [Full GC [PSYoungGen: 58240K->58132K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407700K(466048K) [PSPermGen: 127452K->127452K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2737760 secs] [Times: user=1.16 sys=0.00, real=1.28 secs]
            343.960: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127453K->127453K(127488K)]      GC time is exceeding GCTimeLimit of 98%
            , 1.2624022 secs] [Times: user=1.26 sys=0.00, real=1.27 secs]
            345.229: [Full GC [PSYoungGen: 58240K->58172K(116480K)] [PSOldGen: 349568K->349567K(349568K)] 407808K->407740K(466048K) [PSPermGen: 127453K->127453K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2426333 secs] [Times: user=1.23 sys=0.00, real=1.25 secs]
            346.482: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127461K->127461K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2619984 secs] [Times: user=1.20 sys=0.00, real=1.26 secs]
            347.746: [Full GC [PSYoungGen: 58240K->58173K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407740K(466048K) [PSPermGen: 127461K->127461K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2533929 secs] [Times: user=1.22 sys=0.00, real=1.26 secs]
            09:12:14,527 ERROR [STDERR] Exception in thread "EJB-Timer-1290182816781[target=jboss.j2ee:jndiName=rbs.business.WFTimer,service=EJB]" java.lang.OutOfMemoryError: GC overhead limit exceeded
            349.009: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3366267 secs] [Times: user=1.30 sys=0.00, real=1.35 secs]
            350.356: [Full GC [PSYoungGen: 58240K->58185K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407753K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.4949085 secs] [Times: user=1.50 sys=0.00, real=1.50 secs]
            351.860: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time is exceeding GCTimeLimit of 98%
            , 1.3921265 secs] [Times: user=1.39 sys=0.00, real=1.40 secs]
            353.259: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3378791 secs] [Times: user=1.33 sys=0.00, real=1.34 secs]
            354.603: [Full GC [PSYoungGen: 58240K->58199K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407767K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2869877 secs] [Times: user=1.28 sys=0.00, real=1.29 secs]
            355.899: [Full GC [PSYoungGen: 58240K->58206K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407773K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3913895 secs] [Times: user=1.36 sys=0.00, real=1.40 secs]
            357.297: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.4127568 secs] [Times: user=1.39 sys=0.00, real=1.42 secs]
            358.716: [Full GC [PSYoungGen: 58240K->58209K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407777K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3641995 secs] [Times: user=1.12 sys=0.00, real=1.37 secs]
            360.088: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time is exceeding GCTimeLimit of 98%
            , 1.2688173 secs] [Times: user=1.17 sys=0.00, real=1.27 secs]
            361.364: [Full GC [PSYoungGen: 58240K->58209K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407777K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2582190 secs] [Times: user=1.23 sys=0.00, real=1.27 secs]
            362.644: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2533766 secs] [Times: user=1.26 sys=0.00, real=1.25 secs]
            363.898: [Full GC [PSYoungGen: 58240K->58216K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407784K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3900884 secs] [Times: user=1.37 sys=0.00, real=1.40 secs]
            365.302: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2666269 secs] [Times: user=1.26 sys=0.00, real=1.27 secs]
            366.574: [Full GC [PSYoungGen: 58240K->58221K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407789K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2693027 secs] [Times: user=1.26 sys=0.00, real=1.27 secs]
            367.848: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time is exceeding GCTimeLimit of 98%
            , 1.2435354 secs] [Times: user=1.23 sys=0.00, real=1.24 secs]
            369.094: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2392598 secs] [Times: user=1.23 sys=0.00, real=1.24 secs]
            370.336: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2530421 secs] [Times: user=1.25 sys=0.00, real=1.26 secs]
            371.595: [Full GC [PSYoungGen: 58240K->58223K(116480K)] [PSOldGen: 349567K->349568K(349568K)] 407807K->407791K(466048K) [PSPermGen: 127467K->127467K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3836493 secs] [Times: user=1.37 sys=0.00, real=1.39 secs]
            372.992: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349568K->349568K(349568K)] 407808K->407808K(466048K) [PSPermGen: 127468K->127468K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2320863 secs] [Times: user=1.23 sys=0.00, real=1.23 secs]
            374.225: [Full GC [PSYoungGen: 58240K->58223K(116480K)] [PSOldGen: 349568K->349567K(349568K)] 407808K->407791K(466048K) [PSPermGen: 127468K->127468K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.3659750 secs] [Times: user=1.34 sys=0.00, real=1.37 secs]
            375.601: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127469K->127469K(127488K)]      GC time is exceeding GCTimeLimit of 98%
            , 1.2276298 secs] [Times: user=1.09 sys=0.00, real=1.23 secs]
            376.841: [Full GC [PSYoungGen: 58240K->58225K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407793K(466048K) [PSPermGen: 127469K->127469K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2272470 secs] [Times: user=0.97 sys=0.00, real=1.23 secs]
            378.071: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127471K->127471K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2303878 secs] [Times: user=1.20 sys=0.00, real=1.24 secs]
            379.307: [Full GC [PSYoungGen: 58240K->58225K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407793K(466048K) [PSPermGen: 127471K->127471K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2358059 secs] [Times: user=1.22 sys=0.00, real=1.24 secs]
            09:12:46,071 ERROR [STDERR]     at org.jboss.ejb.txtimer.TimerImpl$TimerTaskImpl.run(TimerImpl.java:588)
            380.552: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127471K->127471K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2428373 secs] [Times: user=1.22 sys=0.00, real=1.27 secs]
            381.820: [Full GC [PSYoungGen: 58240K->58226K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407794K(466048K) [PSPermGen: 127471K->127471K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2355514 secs] [Times: user=1.20 sys=0.00, real=1.24 secs]
            09:12:48,583 ERROR [STDERR]     at java.util.TimerThread.mainLoop(Timer.java:512)
            383.064: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127471K->127471K(127488K)]      GC time is exceeding GCTimeLimit of 98%
            , 1.2329649 secs] [Times: user=1.23 sys=0.00, real=1.24 secs]
            384.308: [Full GC [PSYoungGen: 58240K->58240K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407807K(466048K) [PSPermGen: 127471K->127471K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2323459 secs] [Times: user=1.22 sys=0.00, real=1.24 secs]
            385.547: [Full GC [PSYoungGen: 58240K->58225K(116480K)] [PSOldGen: 349567K->349567K(349568K)] 407807K->407793K(466048K) [PSPermGen: 127471K->127471K(127488K)]      GC time would exceed GCTimeLimit of 98%
            , 1.2355792 secs] [Times: user=1.22 sys=0.00, real=1.24 secs]
            09:12:52,310 ERROR [STDERR]     at java.util.TimerThread.run(Timer.java:462)
            386.792: [Full GC [PSYoungGen: 58240K->0K(116480K)] [PSOldGen: 349567K->334265K(349568K)] 407807K->334265K(466048K) [PSPermGen: 127472K->127471K(127488K)], 1.3806244 secs] [Times: user=1.37 sys=0.00, real=1.39 secs]

            • 3. Re: JBoss Problem with Sun 64-bit JVM
              smarlow

              That is a Java core feature that can be disabled.  Try adding -XX:-UseGCOverheadLimit to your run.conf as a workaround.

               

              The feature tells you if GC is being performed very often.  IMO, It would of been better as a warning message.

              • 4. Re: JBoss Problem with Sun 64-bit JVM
                peterj

                Which version of the JVM are you using? ("Java 6" doesn't tell us anything, significant GC changes have gone into each point release of JDK 6.) What are you JVM options?

                 

                What operating system?

                 

                Essentially, JBoss AS doesn't do anything to control the JVM's GC algorithm; I'm not sure if that is even possible (other than setting commandl ine options). You really need to bring this to the attention of Oracle, they apparently have a bug in thier 64-bit code.

                 

                By the way, my team have used various versions (5.0.x and 6.0.x)  of the 64-bit JVM to do various performance and stress tests on Windows and Linux and never run into an issue like this.

                • 5. Re: JBoss Problem with Sun 64-bit JVM
                  ngoodman310

                  The 64-bit Sun JVM I'm using is:

                  java version "1.6.0_20"
                  Java(TM) SE Runtime Environment (build 1.6.0_20-b02)
                  Java HotSpot(TM) 64-Bit Server VM (build 16.3-b01, mixed mode)

                   

                  The 64-Bit JRockit JVM I'm using is:

                  java version "1.6.0_20"
                  Java(TM) SE Runtime Environment (build 1.6.0_20-b02)
                  Oracle JRockit(R) (build R28.0.1-21-133393-1.6.0_20-20100512-2131-windows-x86_64, compiled mode)

                   

                  The 32-Bit Sun JVM I'm using is:

                  java version "1.6.0_22"
                  Java(TM) SE Runtime Environment (build 1.6.0_22-b04)
                  Java HotSpot(TM) Client VM (build 17.1-b03, mixed mode, sharing)

                   

                  Operating Systems Used:

                  Windows 7 Professional

                  Windows Server 2003

                   

                  I believe you've misread my comments, because the code works correctly with JRockit in all environments.  The only combination that does NOT work is JBoss + Sun 64 Bit JVM.  The same code works in WebLogic with the Sun 64 Bit JVM (which makes no sense, because, as you say, JBoss probably doesn't have any control over the GC).

                  • 6. Re: JBoss Problem with Sun 64-bit JVM
                    ngoodman310

                    I've added that option to the startup args and now, instead of crashing, it's just hanging.  I kindof expected this because the 98/2 error (as I understand it) indicates that the GC is not able to make any progress, so a hang seems likely.  It's also worth noting that on WebLogic with this JVM or JBoss with either of the other JVMs, the query returns to our code in a short period of time.  With the 64 bit JVM and this option set, it's been running for over 4 minutes without returning (it would crash in about 40 seconds without the argument set).

                    • 7. Re: JBoss Problem with Sun 64-bit JVM
                      peterj

                      From what I have read, setting -XX:-UseGCOverheadLimit doesn't help any because all it does is mask the problem.

                       

                      The difference in running JBoss AS and WLS is that they work entirely differently and build different sets of objects and structures to support Java EE. Therefore is is not surprising to see that the same app shows different GC patterns when run in a different app server. And of course JRockit handles GC in a completely different way.

                       

                      You could try upgrading to 1.6.0_22 to see if that helps any. But at least you are not runnign a really old version.

                       

                      You are already monitoring the GC, have you graphed the results to check for patterns?

                      • 8. Re: JBoss Problem with Sun 64-bit JVM
                        ngoodman310

                        What I find odd about this is that the problem occurs within an EclipseLink retrieve.  Ecilpselink is an object-relational mapping library, so I wouldn't expect it to act any differently on JBoss and WebLogic or between JVMs (other than the normal 32-64 bit differences).  I've not graphed the patterns, but i've debugged the problem a bit and it's the creation of objects that's killing the system.

                         

                        We've always assumed that many people use the Sun 64 bit JVM for JBoss (we ported to JBoss about 6 weeks ago); is this an incorrect assumption?  We've had several issues related to GC that have caused crashes (all of them involving object creation duing JDBC calls through EclipseLink).  In these cases, the behavior of WebLogic and JBoss is equivalent (they are both doing non-transactioned [supports] retrieves via a JDBC connection pool and EcilpseLink).  If the problem were in EclipseLink, I'd expect to see it occur on both environments.

                        • 9. Re: JBoss Problem with Sun 64-bit JVM
                          ngoodman310

                          The system actually finally did crash with this error:

                          10:56:19,386 ERROR [STDERR] Exception in thread "EJB-Timer-1290188023311[target=jboss.j2ee:jndiName=rbs.business.WFTimer,service=EJB]" java.lang.OutOfMemoryError: Java heap space

                          • 10. Re: JBoss Problem with Sun 64-bit JVM
                            ngoodman310

                            I should add that 1.6.0_20 is the latest version for windows 64 that's posted on the download site.

                             

                            I forgot that Oracle now controlls both the Sun JVM and the JRockit JVM, so your comment about it being their issue makes more sense to me now (mea culpa).

                            • 11. Re: JBoss Problem with Sun 64-bit JVM
                              peterj
                              it's the creation of objects

                              That is not surprising - a CG happens when an attempt is made to create an object and the young gen (actually, eden) is full. So now you are looking at the odds EclipseLink always being targetted so you have to figure out what percentage of objects are created by it as opposed to other code. And when you think about EJBs, it is mostly data objects that are being created.

                               

                              We've always assumed that many people use the Sun 64 bit JVM for JBoss  (we ported to JBoss about 6 weeks ago); is this an incorrect  assumption?

                              As a gut feeling based on forum posts I would say the ratio is about 1/3 using 64-bit, 2/3 using 32 bit. The defining choice is heap size - usually a 1.2-1.5GB heap is sufficient for most people so they stick with 32-bit.

                               

                              What are you JVM options? Looking at the GC data you posted it loks like nothing but full GCs are happening which is not good. And I must be reading the data incorrectly but it looks like the max heap size is set to something like 450MB.

                              • 12. Re: JBoss Problem with Sun 64-bit JVM
                                smarlow

                                I would look deeper into why your running out of memory.  You can following links on http://www.jboss.org/ for our consulting organization.  They could probably help you figure out what is wrong pretty quickly (if that is the kind of help you want to purchase).

                                 

                                Otherwise, you could generate a Java heap dump when you run out of memory (-XX:-HeapDumpOnOutOfMemoryError) and use the Eclipse Memory Analyzer tool (http://www.eclipse.org/mat/) to figure out what happened.

                                • 13. Re: JBoss Problem with Sun 64-bit JVM
                                  peterj
                                  I should add that 1.6.0_20 is the latest version for windows 64 that's posted on the download site.

                                  Huh? I see 1.6.0_22, that's what I am running. Where are you looking?

                                  http://www.oracle.com/technetwork/java/javase/downloads/index.html

                                  • 14. Re: JBoss Problem with Sun 64-bit JVM
                                    ngoodman310

                                    My current options are:

                                    set MEM_ARGS=-Xms1024m -Xmx2048m -XX:MaxPermSize=1024m
                                    set JAVA_OPTS=%MEM_ARGS% -Xdebug -Xnoagent -Xrunjdwp:transport=dt_socket,address=8787,server=y,suspend=n %JAVA_OPTS%

                                     

                                    I've also set the -Xmx down to 1GB and up to 5GB.  I've manipulated the MaxPermSize from 128m to 4GB.  The boxes I'm on have 6GB and 12GB respectively.  Our production environment reserves 10GB for our application servers.

                                    1 2 Previous Next