Announcement

Collapse
No announcement yet.
X
  • Filter
  • Time
Clear All
new posts

    Heap Memory leak when using DSRequest.execute()!

    Hi Isomorphic Team,

    We are facing an issue in our application where it runs Out Of Memory over time!
    This application has 2 parts - Webapp and an Offline Batch (and both are running into same issue! I'll describe the issue with the batch).

    The Offline Batch runs independently, wherein it does a 'SELECT' from DB every N minutes, and then does some operations with the fetched data.
    Once in a while, it executes Insert/Update/Delete as well.
    Below is a sample program that I created which reproduces the same problem!

    Code:
    import com.isomorphic.base.Config;
    import com.isomorphic.base.ISCInit;
    import com.isomorphic.datasource.DSRequest;
    import org.apache.log4j.Logger;
    
    import java.util.List;
    import java.util.Map;
    
    public class BatchRunner
    {
       private static Logger logger = Logger.getLogger(BatchRunner.class);
    
       private static final String DS_INTEGRATION_TEST = "integrationTests";
       private static final String OP_READ_SINGLE_TEST = "readSingleTestInfo";
       private static final String FETCH_OPERATION = "fetch";
    
       private static final String DB_URL = "jdbc:oracle:thin:@(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=TCP)(HOST=localhost)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=xe)))";
       private static final String DB_CRED = "CMXADMIN";
    
       public static void main (String[] args)
       {
          try
          {
             init();
             while ( true )
             {
                run();
             }
          }
          catch (Exception e)
          {
             logger.error(e.getMessage(), e);
          }
       }
    
       private static void init () throws Exception
       {
          try {
             ISCInit.go();
    
             Config.initGlobalConfig();
    
             Config.getGlobal().put("sql.Oracle.driver.url", DB_URL);
             Config.getGlobal().put("sql.Oracle.driver.user", DB_CRED);
             Config.getGlobal().put("sql.Oracle.driver.password", DB_CRED);
             Config.getGlobal().put("webRoot", System.getProperty("webRoot"));
    
          } catch (Exception e) {
             logger.error(e.getMessage(), e);
             throw new Exception("Failed to load the application", e);
          }
       }
    
       private static void run ()
       {
          try {
             DSRequest dsRequest = new DSRequest();
             dsRequest.setDataSourceName(DS_INTEGRATION_TEST);
             dsRequest.setOperationType(FETCH_OPERATION);
             dsRequest.setOperationId(OP_READ_SINGLE_TEST);
             List record = dsRequest.execute().getDataList();
             log(record);
    //         log(dsRequest.execute().getDataList());
          } catch (Exception e) {
             e.printStackTrace();
          }
       }
    
       // DUMMY METHOD
       private static void log (List<Map<String, Object>> alertRecord)
       {
          logger.info("\n----------------------------------------------------\n");
          Map map = (Map) alertRecord.get(0);
    
          // DO SOMETHING NON-FANCY
          for (Object object : map.keySet())
          {
             logger.info(map.get(object));
          }
          logger.info("\n----------------------------------------------------\n");
       }
    }
    The issue happens when we call the dsRequest.execute() method!
    My guess is that we are not freeing some of the connection resources explictly. However, I tried calling 'freeResources()', or even using 'setFreeOnExecute(true)', but I do not see any difference!
    My ds file is a simple Select query.

    Code:
    <DataSource
            ID="integrationTests"
            serverType="sql"
            tableName="DATABASECHANGELOG"
            dbName="Oracle">
        <fields>
            <field name="ID" type="text" title="Liquibase ID"/>
            <field name="AUTHOR" type="text" title="Author ID"/>
            <field name="FILENAME" type="text" title="FileName"/>
            <field name="CMAX_ORDEREXECUTED" type="text" title="Execution Order" nativeName="CMAX_ORDEREXECUTED"/>
        </fields>
        <operationBindings>
            <operationBinding operationType="fetch" operationId="readSingleTestInfo">
                <selectClause>
                    ID, AUTHOR, FILENAME, CMAX_ORDEREXECUTED
                </selectClause>
            </operationBinding>
        </operationBindings>
    </DataSource>
    I am also attaching a few screenshots that I captured with JProfiler.
    With the tool, I have noticed that the major memory consumer is the method 'DriveManager.getConnection()' and the types are byte[] and char[]! These seem to continuously increase over time, until if finally crashes the JVM!


    P.S:
    Reproduction Env.
    Java 7u45
    Isomorphic Jars - 4.1.1
    IntelliJ IDEA 15.0.x

    IntelliJ VM Options:
    -ea -DwebRoot="C:\mi\Simple_Batch\target\classes" -DdsRoot="C:\mi\Simple_Batch\target\classes\ds" -Dmilogdir="C:\mi\Simple_Batch\logs" -Xmx1024m
    Attached Files

    #2
    As coded, this test case would definitely be expected to leak memory, because you lack a required call to either freeAllResources() or setFreeOnExecute(true) - this is required when executing DSRequests manually, as covered in the docs for freeAllResources().

    You mention that you tried calling freeResources(true) - note this is the wrong API, as it's not documented. freeAllResources() is the documented API.

    Unfortunately, all the diagnostic work you've done is invalid because of the lack of either of these calls. You've also given a version number that doesn't exist (4.1.1), and which is also incomplete (no build date), and you forgot to say what edition of our product you're using.

    We would suggest:
    1. use the latest patch build of whatever product you're using
    2. correct your code as indicated
    3. if you still see a leak, take a look at the diagnostics again in this new situation. If you see something that suggests a framework issue (as opposed to, say, leaky JDBC drivers or leaky log systems), let us know - but remember to include all required information.

    Comment


      #3
      Thanks for the reply.

      However, I still see the issue even though I alternately tried putting in freeAllResources() and setFreeOnExecute(true).

      Code:
      private static void run ()
         {
            try {
               DSRequest dsRequest = new DSRequest();
               dsRequest.setFreeOnExecute(true);
               dsRequest.setDataSourceName(DS_INTEGRATION_TEST);
               dsRequest.setOperationType(FETCH_OPERATION);
               dsRequest.setOperationId(OP_READ_SINGLE_TEST);
               List record = dsRequest.execute().getDataList();
               log(record);
      //         dsRequest.freeAllResources();
      
            } catch (Exception e) {
               e.printStackTrace();
            }
         }
      The leak still exists, the the graphs/leak diagnostics are still very similar.

      SmartGWT Version: Isomorphic SmartClient/SmartGWT Framework (v9.1p_2015-12-11/Enterprise Deployment 2015-12-11)

      Comment


        #4
        Are the results similar, or exactly the same? If they are merely similar, then we need to see updated diagnostics.

        If we are to try to reproduce your problem, we also need:

        1. SQL schema for the table you are targeting
        2. sample data you are running with
        3. exact version of Oracle with are running with
        4. exact version of your JDBC driver

        It's very important to get all these details, because we already have automated tests verifying a lack of connection leaks, so something is special about your environment - possibly a broken JDBC driver.

        Comment


          #5
          The results are the same.

          1. Schema (DDL):
          Code:
          --------------------------------------------------------
          --  DDL for Table DATABASECHANGELOG
          --------------------------------------------------------
          
            CREATE TABLE "CMXADMIN"."DATABASECHANGELOG" 
             (    "ID" VARCHAR2(255 BYTE), 
              "AUTHOR" VARCHAR2(255 BYTE), 
              "FILENAME" VARCHAR2(255 CHAR), 
              "DATEEXECUTED" TIMESTAMP (6), 
              "MD5SUM" VARCHAR2(32 BYTE), 
              "DESCRIPTION" VARCHAR2(255 CHAR), 
              "TAG" VARCHAR2(255 BYTE), 
              "COMMENTS" VARCHAR2(255 CHAR), 
              "LIQUIBASE" VARCHAR2(255 BYTE), 
              "CMAX_ORDEREXECUTED" NUMBER(10,0)
             ) SEGMENT CREATION IMMEDIATE 
            PCTFREE 10 PCTUSED 40 INITRANS 1 MAXTRANS 255 NOCOMPRESS LOGGING
            STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
            PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
            TABLESPACE "SYSTEM" ;
          --------------------------------------------------------
          --  DDL for Index SYS_C008514
          --------------------------------------------------------
          
            CREATE UNIQUE INDEX "CMXADMIN"."SYS_C008514" ON "CMXADMIN"."DATABASECHANGELOG" ("ID", "AUTHOR", "FILENAME") 
            PCTFREE 10 INITRANS 2 MAXTRANS 255 COMPUTE STATISTICS 
            STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
            PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
            TABLESPACE "SYSTEM" ;
          --------------------------------------------------------
          --  Constraints for Table DATABASECHANGELOG
          --------------------------------------------------------
          
            ALTER TABLE "CMXADMIN"."DATABASECHANGELOG" ADD PRIMARY KEY ("ID", "AUTHOR", "FILENAME")
            USING INDEX PCTFREE 10 INITRANS 2 MAXTRANS 255 COMPUTE STATISTICS 
            STORAGE(INITIAL 65536 NEXT 1048576 MINEXTENTS 1 MAXEXTENTS 2147483645
            PCTINCREASE 0 FREELISTS 1 FREELIST GROUPS 1 BUFFER_POOL DEFAULT FLASH_CACHE DEFAULT CELL_FLASH_CACHE DEFAULT)
            TABLESPACE "SYSTEM"  ENABLE;
            ALTER TABLE "CMXADMIN"."DATABASECHANGELOG" MODIFY ("DATEEXECUTED" NOT NULL ENABLE);
            ALTER TABLE "CMXADMIN"."DATABASECHANGELOG" MODIFY ("FILENAME" NOT NULL ENABLE);
            ALTER TABLE "CMXADMIN"."DATABASECHANGELOG" MODIFY ("AUTHOR" NOT NULL ENABLE);
            ALTER TABLE "CMXADMIN"."DATABASECHANGELOG" MODIFY ("ID" NOT NULL ENABLE);
          --------------------------------------------------------
          --  DDL for Trigger DBCHANGELOG_ORDEREXECUTED
          --------------------------------------------------------
          
            CREATE OR REPLACE TRIGGER "CMXADMIN"."DBCHANGELOG_ORDEREXECUTED" 
          BEFORE INSERT
              ON DATABASECHANGELOG
               FOR EACH ROW 
          DECLARE
            v_max number;
          BEGIN
            select nvl(max(CMAX_ORDEREXECUTED),0) into v_max from DATABASECHANGELOG ;
            :new.CMAX_ORDEREXECUTED := v_max + 1;
          END;
          /
          ALTER TRIGGER "CMXADMIN"."DBCHANGELOG_ORDEREXECUTED" ENABLE;
          2. Sample Data (Inserts):
          Code:
          Insert into CMXADMIN.DATABASECHANGELOG (ID,AUTHOR,FILENAME,DATEEXECUTED,MD5SUM,DESCRIPTION,TAG,COMMENTS,LIQUIBASE,CMAX_ORDEREXECUTED) values ('dummy','sg0892439','001.dummy.xml',to_timestamp('01-SEP-14 02.55.57.000000000 PM','DD-MON-RR HH.MI.SSXFF AM'),'77e89ab8d5741dae94581f9b0ff7d','Custom SQL',null,null,'1.9.0',null);
          Insert into CMXADMIN.DATABASECHANGELOG (ID,AUTHOR,FILENAME,DATEEXECUTED,MD5SUM,DESCRIPTION,TAG,COMMENTS,LIQUIBASE,CMAX_ORDEREXECUTED) values ('router_tables','sg0620644','002.router.xml',to_timestamp('01-SEP-14 02.55.57.000000000 PM','DD-MON-RR HH.MI.SSXFF AM'),'cff9249fe7ac5a7aab5ed65e0ef9ff','Custom SQL (x21)',null,null,'1.9.0',null);
          Insert into CMXADMIN.DATABASECHANGELOG (ID,AUTHOR,FILENAME,DATEEXECUTED,MD5SUM,DESCRIPTION,TAG,COMMENTS,LIQUIBASE,CMAX_ORDEREXECUTED) values ('bpm_tables','sg0620644','003.bpm.xml',to_timestamp('01-SEP-14 02.55.58.000000000 PM','DD-MON-RR HH.MI.SSXFF AM'),'b2bf258794f2d44f59d4720b75ba7ef','Custom SQL (x8)',null,null,'1.9.0',null);
          Insert into CMXADMIN.DATABASECHANGELOG (ID,AUTHOR,FILENAME,DATEEXECUTED,MD5SUM,DESCRIPTION,TAG,COMMENTS,LIQUIBASE,CMAX_ORDEREXECUTED) values ('bpm_tables_2','sg0620644','004.bpm2.xml',to_timestamp('01-SEP-14 02.55.58.000000000 PM','DD-MON-RR HH.MI.SSXFF AM'),'d76501ce6384b998b50b1ac6074ce69','Custom SQL (x14)',null,null,'1.9.0',null);
          Insert into CMXADMIN.DATABASECHANGELOG (ID,AUTHOR,FILENAME,DATEEXECUTED,MD5SUM,DESCRIPTION,TAG,COMMENTS,LIQUIBASE,CMAX_ORDEREXECUTED) values ('router_2','sg0620645','005.router2.xml',to_timestamp('01-SEP-14 02.55.58.000000000 PM','DD-MON-RR HH.MI.SSXFF AM'),'bf5ecdb9b4a90f520e9cd83cc4c5bc','Custom SQL (x2)',null,null,'1.9.0',null);
          3. Oracle Version:
          Oracle Database 11g Release 2 (11.2.0.4)

          4. JDBC Version and Other libs (pom.xml)

          JDBC Version - 11.2.0.4

          pom.xml is as attached!
          Attached Files

          Comment


            #6
            We've tried a few different ways, and we're not replicating these results. We are not only showing no leak, we can't even get a leak of the magnitude you're reporting when we intentionally write broken code (leaving out freeOnExecute).

            We mimicked your environment exactly as far as the SmartGWT version, JDBC driver and Oracle version (except we used Express). We also tried a corresponding test with MySQL, and also got no leak.

            Most likely, you are probably running additional software or monitoring tools which you have no disclosed which are actually causing the leak. Or you are perhaps not actually running with the reported versions of our software or other related software.

            Let us know if you can reproduce a leak with a completely clean install on a new system with no other software installed at all.

            Comment


              #7
              Hi.
              Sorry for the delay in reply, was caught up in some pressing issues!
              As for the problem, I do not see the leak anymore, the possible reason could be:
              In Production (and in my first post scenario), the Isomorphic SmartGWT version was Isomorphic SmartClient/SmartGWT Framework (v9.1p_2014-06-22/Enterprise Deployment 2014-06-22). After your reply, I had downloaded the latest patch, and was trying with that. Looks like some JARs were not replaced properly (my bad!), and thus I was still seeing the issue. I do not see the issue anymore with the version Isomorphic SmartClient/SmartGWT Framework (v9.1p_2015-12-11/Enterprise Deployment 2015-12-11).

              However, could you also please confirm once on your side so that we can be fully sure that the issue was due to the 2014-06-22 version of the JARs?

              Thanks for your help!
              Last edited by pankaj.jain; 6 Jan 2016, 01:27.

              Comment


                #8
                Sorry, we don't plan to investigate further here to try to confirm whether there was a bug in older jars vs something else wrong with your setup (such as mixed jars).

                If you really want to invest efforts in further confirmation we would recommend a from-scratch setup with each version so that you avoid any further confusion about .jars.

                Comment


                  #9
                  Well, I think the memory leak's been resolved with the new jars.
                  I do not see any more indication of leaks yet.
                  However, the new jars seem to be causing some issue in our webapp, though I need to investigate further. (some issue with grid, getting an NPE!)
                  If the webapp thing really is an issue, then probably i'll open another thread, but for now, the leak issue is resolved.

                  Thanks!

                  Comment

                  Working...
                  X