6 Replies Latest reply: Oct 15, 2012 5:41 PM by swa_jacfin RSS

    olt-agent.exe using 1.2Gb memory for only 30 VUs and growing!

    swa_jacfin
      Hi,

      I'm new to the OLT application and having been trying it out over the last couple of days load testing some Oracle database stored procedures. The stored procedures are now being called OK but I cannot run the tests for more than 60 minutes before it exhausts memory. I am only running 30 VUs spread across 6 different scripts in the 1 scenario. I have turned off all VU logging and report counters but I still see the memory grow.

      3 olt-agents are run on one machine (4Gb memory), 1 olt-agent is started on another machine (1Gb memory). All 4 agents show continuous memory growth going past 300Mb but the first one started can hit 1.2Gb. I've read elsewhere that I should allow about 1Mb per VU so this is all a bit crazy. The olt-agent.exe all start off initially at 132Mb and grow from there.

      All machines are Windows XP and I have downloaded the lastest OLT. JRE 1.6 is being used

      Has anybody encountered what appears to be a memory leak in the running of the openscripts under OLT? Is there anyway to control the size of the olt-agent.exe?

      From agentmanager.log:
      17:30:37,881 INFO [EmpStartMain] Listening on port: 9001
      17:32:02,949 INFO [Messenger] Try server=t3://xxxxxxxxxxxxxx destination=oracle/oats/queue/AgentPoolNotificationQueue
      17:32:04,570 INFO [Messenger] Got ConnectionFactory
      17:32:04,601 INFO [Messenger] Got destination oracle/oats/queue/AgentPoolNotificationQueue
      17:32:10,430 INFO [Messenger] Created connection.
      17:32:10,477 INFO [Messenger] Created queue session.
      17:32:10,508 INFO [Messenger] Connected to server=t3://xxxxxxxxxxxxxxxxxx destination=oracle/oats/queue/AgentPoolNotificationQueue
      17:32:10,508 INFO [Request] [URL:t3://xxxxxxxxxxxxxxxxxxxx ;Requestor Username: oats-agent;Requestor Key:4cca63a5-9b79-43a5-8a96-4eaba9ba162d;Requestor Queue:oracle/oats/queue/AgentPoolNotificationQueue;Request ID:25;Request:startagent;] - authentication successful
      17:32:10,524 INFO [EmpStartMain] handleStartAgentRequestRequest ID: 25, RKey: 4cca63a5-9b79-43a5-8a96-4eaba9ba162d, RUrl: t3://xxxxxxxxxxxxxxxx, RUsername: oats-agent, RQueue : oracle/oats/queue/AgentPoolNotificationQueue, Request: startagent, Agent Type: empJAgent.exe, Agent ID: agId2568_rnd286169fc-ce5b-4b21-807d-4e273673ef86, Agent Cmd : empJAgent.exe -classpath determinedAtRunTime oracle.oats.jagent.EntryPoint jms /token: /id:agId2568_rnd286169fc-ce5b-4b21-807d-4e273673ef86 /version:12.1.0.2.58 /clusterurl:t3://xxxxxxxxxxxxxxxx /clusterhttpurl:http://xxxxxxxxxxxxxxxxxx/pooltopic:oracle/oats/topic/AgentPoolControlTopic /poolqueue:oracle/oats/queue/AgentPoolNotificationQueue, Agent Checksum: [], Agent Credential Type: default, Version: 12.1.0.2.58
      17:32:10,524 INFO [SettingsHandler] extracted 'debug' command line params for null:
      17:32:10,524 INFO [ProcessRunner]
      startAgent(
      pathToExe=C:\OracleATS\jdk\jre\bin\olt-agent.exe
      cmdLineArgs=-jrockit -Xrs -XgcPrio:deterministic -XpauseTarget=50ms -XX:+UseCallProfiling -XX:+UseAdaptiveFatSpin -XX:+ExitOnOutOfMemoryError -XXnoSystemGC -XX:+UseFastTime -classpath ;C:\OracleATS\agent\jars\EntryPointWrapper.jar;C:\OracleATS\agent\jars\Framework.jar oracle.oats.jagent.EntryPointWrapper oracle.oats.jagent.EntryPoint -installdir C:\OracleATS\jdk\jre\..\.. jms /token: /id:agId2568_rnd286169fc-ce5b-4b21-807d-4e273673ef86 /version:12.1.0.2.58 /clusterurl:t3://xxxxxxxxxxxxxx/clusterhttpurl:http://xxxxxxxxxxxxxxxxxx/pooltopic:oracle/oats/topic/AgentPoolControlTopic /poolqueue:oracle/oats/queue/AgentPoolNotificationQueue
      workingDir=C:\OracleATS\agent
      agentId=agId2568_rnd286169fc-ce5b-4b21-807d-4e273673ef86
      requestor=4cca63a5-9b79-43a5-8a96-4eaba9ba162d), returning ID 1)
      17:32:10,540 INFO [AgentProcess] Launching agent 4cca63a5-9b79-43a5-8a96-4eaba9ba162d:agId2568_rnd286169fc-ce5b-4b21-807d-4e273673ef86
           cmdLine=C:\OracleATS\jdk\jre\bin\olt-agent.exe -jrockit -Xrs -XgcPrio:deterministic -XpauseTarget=50ms -XX:+UseCallProfiling -XX:+UseAdaptiveFatSpin -XX:+ExitOnOutOfMemoryError -XXnoSystemGC -XX:+UseFastTime -classpath ;C:\OracleATS\agent\jars\EntryPointWrapper.jar;C:\OracleATS\agent\jars\Framework.jar oracle.oats.jagent.EntryPointWrapper oracle.oats.jagent.EntryPoint -installdir C:\OracleATS\jdk\jre\..\.. jms /token: /id:agId2568_rnd286169fc-ce5b-4b21-807d-4e273673ef86 /version:12.1.0.2.58 /clusterurl:t3://xxxxxxxxxxxxxx/clusterhttpurl:http://xxxxxxxxxxxxxxxxxxxxx/pooltopic:oracle/oats/topic/AgentPoolControlTopic /poolqueue:oracle/oats/queue/AgentPoolNotificationQueue
           workingDir=C:\OracleATS\agent
      17:32:10,555 INFO [AgentProcess] Launched process 5694979 for agent agId2568_rnd286169fc-ce5b-4b21-807d-4e273673ef86
        • 1. Re: olt-agent.exe using 1.2Gb memory for only 30 VUs and growing!
          glenn.s
          Do you have the same problem when you only run one user? I assume you will, if it's a true memory leak, though it may take longer to witness. In general you should validate each script running only one user.

          If it is only happening with more virtual users, then it could be queued reporting data sent back to the controller. Are you running too fast for the agent to keep up with it's reporting to the Controller? At least 1 second iteration delay is recommended.

          You inserted the stored procedures into a script yourself, or are you using the Load Testing Accelerator for Oracle Database? I know you say you have turned off reporting, but for memory problems with too much report data sending to the controller, these are some recommendations:

          In each of the profiles (or change your scenario defaults)
          1) Report Counters = FALSE - is this the one you say is already set to FALSE?

          2) Report Sender Interval - default is 5000 milliseconds. It may seem counter intuitive, but sometimes if there is too much data for the agent to package and send the Controller, it needs more time. Increasing this helps in that case. Agent proc CPU flat lining for long periods of time would indicate data packaging overhead. Try 30000, and then somewhere in the middle.
          3) Maximum JVM Heap Size (MB) - increase this, in case mem trashing is causing a side affect. Try an extreme of 2048 which is much higher than the default of 256.
          4) Auto Generate Timers For All Pages (and Step Groups and All Resources) = FALSE

          --
          The agentmanager.log file you have posted is only helpful to show the startup arguments that were used to kick off the virtual agent process. You need the java_agent.log file to see virtual agent information. On your agent machine change the log4j.xml file to debug log more things. You can see there are other examples of log4 files in the agent directory as well.

          cd \oracleats\agent

          ' backup the old file
          copy log4j.xml log4j-install.xml

          ' This is an example of a debugall options. Not recommenced for your case, but you can get the idea of what can be logged.
          ' log4j-debugall.xml log4j.xml
          • 2. Re: olt-agent.exe using 1.2Gb memory for only 30 VUs and growing!
            swa_jacfin
            Thanks!

            I will have a look into these options and let you know the result. I have an hour or two free this afternoon.

            Stuart
            • 3. Re: olt-agent.exe using 1.2Gb memory for only 30 VUs and growing!
              swa_jacfin
              IN response to the questions

              Are you running too fast for the agent to keep up with it's reporting to the Controller? At least 1 second iteration delay is recommended.
              I am running with No Delay. I will add a delay in but I will have to increase the number of VUs to mimic the production system
              You inserted the stored procedures into a script yourself, or are you using the Load Testing Accelerator for Oracle Database?
              I created the script myself in OpenScript.
              In each of the profiles (or change your scenario defaults)
              1) Report Counters = FALSE - is this the one you say is already set to FALSE?
              Yes. I turned this off. I had the same thought as you with the controller being overwhelmed and not being able to store the data quick enough
              • 4. Re: olt-agent.exe using 1.2Gb memory for only 30 VUs and growing!
                swa_jacfin
                Some interesting test results.

                Just executing a "select 1 from dual" using a plain SQL call in openscript I get a fairly stable memory footprint on the olt-agent. Stays at about 140Mb regardless of the number of VUs. I noticed the memory did go up slowly so set a iteration delay of 1sec and the memory stayed constant with throughput at 40/sec

                I switched to a openscript calling a StoredProcedure which returns some OUT parameters and defined each of the 11 OUT parameters in the List Object for the SQL utilities parameter service. Running with the same set up as the "Select 1 from Dual" test before (ie. 40 VUs) my 4Gb of memory was exhausted in a stunning 2 minutes flat by the olt-agent.

                     public void run() throws Exception {
                          getDatabank("MSISDN_GetAccountType").getNextDatabankRecord();
                          utilities.getSQLService().callProcedure("ssb", "DECLARE \r\nBEGIN \r\n{ call VF_SELFCARE.GETACCOUNTTYPE (?,?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?);\r\n}\r\nEND; ",
                                    utilities.parameters(
                                         SQLService.parameter("{{db.MSISDN_GetAccountType.MSISDN}}",SQLService.SQLParameterType.In),
                                         SQLService.parameter("{{db.MSISDN_GetAccountType.TYPE}}",SQLService.SQLParameterType.In),
                                         SQLService.parameter("ACCOUNT_NAME",SQLService.SQLParameterType.Out),
                                         SQLService.parameter("ACCOUNT_TYPE",SQLService.SQLParameterType.Out),
                                         SQLService.parameter("PAYMENT_METHOD",SQLService.SQLParameterType.Out),
                                         SQLService.parameter("IS_COMPLEX",SQLService.SQLParameterType.Out),
                                         SQLService.parameter("ACCOUNT_STATUS",SQLService.SQLParameterType.Out),
                                         SQLService.parameter("BILL_CYCLE",SQLService.SQLParameterType.Out),
                                         SQLService.parameter("LIVE_CONNECTIONS",SQLService.SQLParameterType.Out),
                                         SQLService.parameter("PARENT_ACCOUNT",SQLService.SQLParameterType.Out),
                                         SQLService.parameter("INSTALLED_ASSETS",SQLService.SQLParameterType.Out),
                                         SQLService.parameter("RESULT_CODE",SQLService.SQLParameterType.Out),
                                         SQLService.parameter("RESULT_MESSAGE",SQLService.SQLParameterType.Out)
                                    )
                          );
                     }

                It seems the Openscript SQL Service for stored procedures is causing me some problems. I suspect the return OUT parameters, and maybe the IN, are being somehow stored in memory for the olt-agent and not cleared on each call. I wonder if there is a way to destroy the List Object returned by the utilities.parameter service.

                Stuart
                • 5. Re: olt-agent.exe using 1.2Gb memory for only 30 VUs and growing!
                  glenn.s
                  Is There a ResultSet that needs to be closed? Is there a function in the sqlService that can help you clean up?
                  import java.sql.ResultSet;
                  import java.util.Iterator;
                  ...
                       SQLService sqlSvc = utilities.getSQLService();
                       List<Object> myList = sqlSvc.callProcedure("", "");
                            
                       Iterator<Object> iterator = myList.iterator();
                  
                          // go thru all the object that were returned
                       while (iterator.hasNext()) 
                       {
                            Object nextItem = iterator.next();
                                 
                            // HELP print out the type of object
                            this.info("Item Object Type = " + nextItem.getClass().getName());
                            
                            // is it a ResultSet     
                            if (nextItem instanceof ResultSet)
                            {
                                 ResultSet rs = (ResultSet) nextItem;
                  
                                 // CLOSE The ResultSet
                                 rs.close();
                            }
                       }
                  
                       // just test if disconnecting from the DB helps. Probably not want you want to do every iteration
                          sqlSvc.disconnect("ssb");
                  • 6. Re: olt-agent.exe using 1.2Gb memory for only 30 VUs and growing!
                    swa_jacfin
                    Hi,

                    No luck with the above options. Have also tried various options with clearing the objects (MyObject.clear()) etc but the memory growth continues. Note that even if the stored proc only returns strings (ie. no sys_refcursor result sets) I still observe crazy memory growth.

                    I was watching the Oracle 10G EX database and it doesn't seem under pressure with writes. Nevertheless, even with report counters and all other reporting and persistent data turned off I still see olt-agent memory usage going high.

                    Btw, thanks for the tip on accessing the Lists and the ResultSet. Priceless stuff as I can see other people have been looking for help on this.

                    I have an SR raised with Oracle and they are actively looking into it much to my surprise. Will keep this updated with resolution if one is provided

                    Stuart