Search code examples
javacoldfusiongarbage-collectionjvmcoldfusion-9

coldFusion jvm Garbage Collection not


I have a cfc method that is looping through a list and making a series of SOAP calls via cfhttp. Then inserts the result into a database.

The process itself works great the problem is that the java memory slowly fills up and eventually (depending on the number of elements in the records being returned) just stops working. There is no error or anything visible it just stops. If I look at the application log file via the coldfusion admin I see one or both of the following errors:

GC overhead limit exceeded The specific sequence of files included or processed is:

or

Java heap space The specific sequence of files included or processed is:

Below is simplified version of the code I am running:

<cfsetting requesttimeout="3600">
<cfloop condition="thisPass lt 10">
    <cfscript>
        runtime = CreateObject("java","java.lang.Runtime").getRuntime();
        objSystem = CreateObject( "java", "java.lang.System" );
        soapBody = '';
        soapResponse = '';
        thisStruct = '';
        lock scope='application' type='exclusive' timeout='60' {


//This is where I am trying to manage the memory and call garbage collection


        try {
            freeMemory = runtime.freeMemory()/1024/1024;
            writeOutput("- fm = "&freeMemory);
            if (freeMemory < 200){
                objSystem.gc();
                sleep(1000);
                writeDump(' - dumping freeMemory');
             }
         }
         catch(any error) {
            writeDump(' - trying to dump GC as '&now()& ' freeMemory = '&freeMemory);
         }
         }
        </cfscript>
        <cfsavecontent variable="soapBody">
            <?xml version="1.0" encoding="utf-8"?>
            [ BUILD SOAP ENVELOP ]
        </cfsavecontent>

        <cfhttp url="[URL]" method="post" result="httpResponse" 
                        timeout="600" resolveurl="false">
                <cfhttpparam type="header" name="SOAPAction" value="[URL2]" />
                <cfhttpparam type="xml" value="#trim( soapBody )#"/>
            </cfhttp>


            <cfscript>
                soapBody = "";
                soapResponse = httpResponse.fileContent;
                soapResponse = xmlParse( soapResponse );
                thisStruct = xmlSearch(soapResponse,'/soap:Envelope/soap:Body/')[1].xmlChildren[1].xmlChildren[1].xmlChildren;
                writeOutput("-"&arrayLen(thisStruct)&' records');
                getPageContext().getOut().flush();
                if(arrayLen(thisStruct) == 2500){
                    thisPass = thisPass+1;
                } else {
                    writeOutput("- total records = "&(2500*(thisPass-1))+arrayLen(thisStruct));
                    thisPass = 100; // since looping while thisPass lt 10 this should prevent the next iteration
                }
            </cfscript>

            <cfloop from="1" to="#arrayLen(thisStruct)#" index="i">
                [RUN PROC TO INSERT RECORDS]
            </cfloop>
        </cfloop>

The GC seems to sometimes release a bit of memory but not with any reliability. I understand that GC() is only a recommendation for java to release some of the unused memory but I am unsure how I can get it to FORCE it to release memory. It is possible that there is a leak somewhere but I am not seeing it. I am hoping that this is something obvious that I have over looked and I admit that my java knowledge is extremely limited.

Is there some java guru out there that can see my error?

UPDATE : Here is a sample of the output incase this is helpfule to see the decline of memory.

there are 236 lists to loop through

  1. 88185 - fm = 293.564407349 -6 records- total records = 6
  2. 88389 - fm = 290.86995697 -116 records- total records = 116
  3. 88390 - fm = 308.382568359 -262 records- total records = 262
  4. 88839 - fm = 292.707099915 -2032 records- total records = 2032
  5. 91088 - fm = 290.711753845 -6 records- total records = 6
  6. 92998 - fm = 287.754066467 -5 records- total records = 5
  7. 95510 - fm = 309.919425964 -91 records- total records = 91
  8. 96478 - fm = 292.035064697 -1180 records- total records = 1180
  9. 96479 - fm = 259.001213074 -1113 records- total records = 1113
  10. 96480 - fm = 261.121406555 -110 records- total records = 110
  11. 96796 - fm = 267.235244751 -2 records- total records = 2
  12. 96799 - fm = 265.037582397 -0 records- total records = 0
  13. 97435 - fm = 263.589103699 -2500 records - fm = 227.629760742 -2500 records - fm = 200.85987854 -2500 records - fm = 202.156776428 -2500 records - fm = 166.366210938 - dumping freeMemory -656 records- total records = 10656
  14. 98173 - fm = 160.579734802 - dumping freeMemory -35 records- total records = 35
  15. 99111 - fm = 176.218482971 - dumping freeMemory -0 records- total records = 0
  16. 100998 - fm = 194.708694458 - dumping freeMemory -185 records- total records = 185
  17. 101811 - fm = 160.61415863 - dumping freeMemory -2500 records - fm = 112.862670898 - dumping freeMemory -2500 records - fm = 86.2071380615 - dumping freeMemory -2500 records - fm = 52.9639358521 - dumping freeMemory -1064 records- total records = 8564
  18. 105014 - fm = 56.1721343994 - dumping freeMemory -14 records- total records = 14
  19. 105992 - fm = 73.0022964478 - dumping freeMemory -14 records- total records = 14
  20. 107539 - fm = 75.9522399902 - dumping freeMemory -93 records- total records = 93
  21. 107580 - fm = 58.345199585 - dumping freeMemory -2500 records

Solution

  • After a lot searching I found that the best "fix" for this particular problems was to remove the code that was attempting to do the garbage collection and increase the java heap sizes. In the /jrun/bin/jvm.config file.

    By changes the Arguments to VM to :

    java.args=-server -Xms2048m -Xmx2048m -Xmn1024m -Dsun.io.useCanonCaches=false -XX:MaxPermSize=192m -XX:+UseParallelGC -Xbatch -Dcoldfusion.rootDir={application.home}/ -Djava.security.policy={application.home}/servers/cfusion/cfusion-ear/cfusion-war/WEB-INF/cfusion/lib/coldfusion.policy -Djava.security.auth.policy={application.home}/servers/cfusion/cfusion-ear/cfusion-war/WEB-INF/cfusion/lib/neo_jaas.policy
    

    I was able to increase the initial heap size (Xms) and the max heap size (Xmx) to 2048m and the and the "young generation" heap size (Xmn) to 1024m Since it was suggested to me that the young generation should be smaller than the initial and max for better garbage collection.

    As suggested by James, I commented out the actual processes (which are in a function and var'd) and then uncommenting them one at a time running everything each time. What I learned by this was that the large SOAP responses were what was filling up the memory and not a leak as I had feared.

    As Adam mentioned, it it wasn't about Java managing the GC but rather there wasn't enough room to manage was I was throwing at at (for some reason CF doesn't like to deal with 2500 record SOAP responses very well) go figure.

    Adam was also correct saying that trouble shooting Java memory in CF is a "dark art" By using the server monitor http://localhost/CFIDE/administrator/monitor/launch-monitor.cfm and going to the statistics tab under Memory Usage -> Memory Usage Summary I could watch the memory slowly fill up and dump itself even when after a fresh reboot no processes where running. Never was able to figure out why but I could see what levels were running and that I was hitting the top.

    The default memory allocated in the jvm.config file was 512m and simply wasn't enough to handle what was going on. There may be a better way to handle this overall process. May have to implement Henry's suggestion and put it in the database and chunk through it, although that sounds very clumsy to me.

    I am sure that other then CF now taking up a huge chunk of resources right out of the gate there may be other problems with this solution but (for now) it seems to be working as needed.

    UPDATE : I changed the cfc function so that instead of inserting everything into the database I wrote all the XML to files and and then read the file and insert into the database. Somehow the writing to file allowed java to "breath" long enough to do the GC() itself.