2 Replies Latest reply on Aug 4, 2004 3:26 PM by crowse

    Performance issue , 2 local String getXXX(32Byte) take  95 m

    crowse
    crowse Aug 4, 2004 7:52 AM

      Hi,
      I am having problems trying to materialize a list of 30000 key/value pairs off a MS SQL server using JBoss CMP.

      The log shows that the system spends 95% of its time in the 2 get methods (returning strings).

      I must be missing a configuration error in XDoclet or JBoss.

      The 'Raw' SQL server is capable of returning the result set in about 1 second.

      I can write PO JDBC but that increases my maintenance burden.

      Can anyone tell me what I am doing wrong?

      12:10:48,758 ERROR [STDERR] 04-Aug-2004 12:10:48 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:0ms getBean: 0ms getValue: 0ms put: 0ms ................ Loaded 0 in 646 ms
12:12:23,828 ERROR [STDERR] 04-Aug-2004 12:12:23 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:648ms getBean: 1ms getValue: 95030ms put: 37ms ................ Loaded 1000 in 95716 ms
12:13:59,149 ERROR [STDERR] 04-Aug-2004 12:13:59 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:651ms getBean: 2ms getValue: 190306ms put: 77ms ................ Loaded 2000 in 191036 ms
12:15:34,018 ERROR [STDERR] 04-Aug-2004 12:15:34 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:661ms getBean: 5ms getValue: 285132ms put: 108ms ................ Loaded 3000 in 285906 ms
12:17:09,052 ERROR [STDERR] 04-Aug-2004 12:17:09 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:666ms getBean: 8ms getValue: 380139ms put: 127ms ................ Loaded 4000 in 380940 ms
12:18:44,065 ERROR [STDERR] 04-Aug-2004 12:18:44 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:669ms getBean: 9ms getValue: 475130ms put: 145ms ................ Loaded 5000 in 475953 ms
12:20:18,744 ERROR [STDERR] 04-Aug-2004 12:20:18 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:683ms getBean: 10ms getValue: 569780ms put: 159ms ................ Loaded 6000 in 570632 ms
12:21:53,426 ERROR [STDERR] 04-Aug-2004 12:21:53 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:691ms getBean: 10ms getValue: 664439ms put: 174ms ................ Loaded 7000 in 665314 ms
12:23:27,820 ERROR [STDERR] 04-Aug-2004 12:23:27 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:698ms getBean: 13ms getValue: 758809ms put: 188ms ................ Loaded 8000 in 759708 ms
12:25:02,600 ERROR [STDERR] 04-Aug-2004 12:25:02 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:703ms getBean: 15ms getValue: 853564ms put: 206ms ................ Loaded 9000 in 854488 ms
12:26:37,204 ERROR [STDERR] 04-Aug-2004 12:26:37 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:707ms getBean: 17ms getValue: 948144ms put: 224ms ................ Loaded 10000 in 949092 ms
12:28:11,657 ERROR [STDERR] 04-Aug-2004 12:28:11 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:713ms getBean: 21ms getValue: 1042566ms put: 245ms ................ Loaded 11000 in 1043545 ms
12:29:45,852 ERROR [STDERR] 04-Aug-2004 12:29:45 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:716ms getBean: 25ms getValue: 1136736ms put: 263ms ................ Loaded 12000 in 1137740 ms
12:31:20,152 ERROR [STDERR] 04-Aug-2004 12:31:20 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:723ms getBean: 27ms getValue: 1231011ms put: 279ms ................ Loaded 13000 in 1232040 ms
12:32:57,038 ERROR [STDERR] 04-Aug-2004 12:32:57 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:727ms getBean: 28ms getValue: 1327882ms put: 288ms ................ Loaded 14000 in 1328925 ms
12:34:30,165 ERROR [STDERR] 04-Aug-2004 12:34:30 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:736ms getBean: 30ms getValue: 1420974ms put: 313ms ................ Loaded 15000 in 1422053 ms
12:36:07,270 ERROR [STDERR] 04-Aug-2004 12:36:07 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:741ms getBean: 30ms getValue: 1518054ms put: 332ms ................ Loaded 16000 in 1519158 ms
12:37:44,429 ERROR [STDERR] 04-Aug-2004 12:37:44 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:745ms getBean: 32ms getValue: 1615191ms put: 349ms ................ Loaded 17000 in 1616317 ms
12:39:19,519 ERROR [STDERR] 04-Aug-2004 12:39:19 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:746ms getBean: 33ms getValue: 1710267ms put: 361ms ................ Loaded 18000 in 1711407 ms
12:39:27,113 ERROR [STDERR] 04-Aug-2004 12:39:27 natis.servlet.MSIxStateBeanListServlet reload
INFO: MSIxStateBeanList.init() ....next:747ms getBean: 33ms getValue: 1717859ms put: 362ms ................ Loaded 18082 in 1719001 ms
12:39:27,139 ERROR [STDERR] 04-Aug-2004 12:39:27 natis.servlet.Mf2NatisServlet build



      here is the code fragment 
      
 MSIxStateBeanLocalHome home = (MSIxStateBeanLocalHome)
 initialContext.lookup(MSIxStateBeanLocalHome.JNDI_NAME);
 if (home==null) home=MSIxStateBeanUtil.getLocalHome();

 Collection c = home.findAll(); // findIndex();
 Iterator it = c.iterator();

 while (it.hasNext()) {
 if ((cnt % 1000) ==0) {
 logger.log(Level.INFO,"MSIxStateBeanList.init() ....next:" + times[0]
 + "ms getBean: " + times[1]
 + "ms getValue: " + times[2]
 + "ms put: " + times[3]
 + "ms ................ Loaded " + cnt
 + " in " + (System.currentTimeMillis()-t0) + " ms");
 }
 Object obj= it.next();
 ty=System.currentTimeMillis();
 times[0] += ty-tx;
 tx = ty;

 try {
 MSIxStateBeanLocal v = (MSIxStateBeanLocal) obj;
 // PortableRemoteObject.narrow(obj,MSIxStateBeanRemote.class);
 ty=System.currentTimeMillis();
 times[1] += ty-tx;
 tx = ty;

 // MSIxStateBeanValue vb = v.getValue(); // 96 sec/1000 on Oak
 String id = v.getId();
 String unit= v.getUnitN();

 ty=System.currentTimeMillis();
 times[2] += ty-tx;
 tx = ty;
 putStateBean(id, unit);

 ty=System.currentTimeMillis();
 times[3] += ty-tx;
 tx = ty;

 cnt++;
 } catch (Exception exc) {
 logger.log(Level.SEVERE,"servlet.MSIxStateBeanList.init() Exception : " ,exc);
 }
 }


      And the bean 

      package tet.ejb;
import java.io.UnsupportedEncodingException;
import java.rmi.RemoteException;

/*
import java.text.NumberFormat;
import java.text.DateFormat;
import java.text.SimpleDateFormat;
import java.util.Calendar;
import java.util.Date;
import java.util.logging.*;
*/

import util.interfaces.Identifiable;
import natis.interfaces.MSIxStateBeanValue;
import javax.ejb.*;
import util.ejb.BaseEntityBean;

/** This is State Index
 * <UL>
 * <LI>Read only
 * <LI>Contains UnitN and ID of StateBeanMS</li>
 * </ul>
 *
 * @ejb.bean
 * name="MSIxStateBean"
 * jndi-name="ejb/mssql/MSIxStateBeanRemote"
 * local-jndi-name="ejb/MSIxStateBeanLocal"
 * view-type="both"
 * type="CMP"
 * cmp-version="2.x"
 * primkey-field="id"
 * business-interface="test.interfaces.MSIxStateBeanRemote"
 *
 * @ejb.facade type="stateless"
 * name="{0}Facade"
 * jndi-name="{0}Facade"
 * local-jndi-name="{0}LocalFacade"
 * view-type="both"
 * transaction-type="Container"

 * @ejb.home
 * local-class="test.interfaces.MSIxStateBeanLocalHome"
 * remote-class="test.interfaces.MSIxStateBeanRemoteHome"
 * @ejb.interface
 * local-class="test.interfaces.MSIxStateBeanLocal"
 * remote-class="test.interfaces.MSIxStateBeanRemote"
 *
 * @ejb.finder
 * signature="Collection findAll()"
 * role-name="Administrator"
 * transaction-type="NotSupported"
 * unchecked="true"
 *
 * @ejb.persistence
 * table-name="StateBeanMS_001"
 * read-only="true"
 *
 * @ejb.pk
 * generate="false"
 * unchecked="true"
 *
 * @jboss.ejb-external-ref-jndi
 * jndi-name="/UUIDKeyGeneratorFactory"
 * ref-name="comp:env/keygenerator"
 *
 * @jboss.create-table "false"
 * @jboss.remove-table "false"
 * @jboss.tuned-updates "${jboss.tuned.updates}"
 * @jboss.read-only "true"
 * @jboss.read-ahead strategy="on-find"
 * page-size="1000"
 *
 * @jboss.persistence
 * datasource="java:/MSSQLDS"
 * datasource-mapping="MS SQLSERVER2000"
 * table-name="StateBeanMS_001"
 * create-table="false"
 * remove-table-"false"
 * read-time-out="2000"
 * row-locking="false"
 * fetch-size="1000"

 * @ejb.security-identity
 * run-as="sa"
 *
 * @ejb.value-object
 * match="*"
 *
 * @version $Revision: 1.17 $
 * @author <a href="mailto:chris@forth.co.za@forthtree.co.za">Chris@forth.co.za</a>
 */
public abstract class MSIxStateBean extends BaseEntityBean implements EntityBean, Identifiable {

 /**
 * @ejb.interface-method
 * view-type="both"
 * @ejb.value-object
 * exclude="true"
 * match="*"
 */
 public test.interfaces.MSIxStateBeanValue getValue() {
 MSIxStateBeanValue v = new MSIxStateBeanValue();
 v.setId(getId());
 v.setUnitN(getUnitN());
 return v;
 }

 /**
 * Id of this StateBean. This is not remote since the primary key can be extracted by other means.
 *
 * @ejb.pk-field
 * class="java.lang.String"
 * @ejb.interface-method
 *
 * @ejb.persistence column-name="StateBean_id"
 * @ejb.permission
 * role-name="Administrator"
 * @jboss.method-attributes read-only="true"
 *
 */
 public abstract String getId();

 /**
 * @ejb.value-object
 * exclude="false"
 * match="*"
 */

 public abstract void setId(String id);

 /**
 * @ejb.permission
 * role-name="Administrator"
 * @ejb.value-object
 * exclude="false"
 * match="*"
 * @ejb.persistence
 * column-name="unitN"
 * sql-type="varchar(255)"
 * @ejb.interface-method
 * view-type="both"
 *
 * @jboss.method-attributes read-only="true"
 */
 public abstract String getUnitN();

 /**
 * @ejb.value-object
 * exclude="false"
 * match="*"
 *
 * @jboss.method-attributes read-only="true"
 */
 public abstract void setUnitN(String modelJob);

 public void ejbStore() throws EJBException {
 }

 /**
 * This is to get the unknown primary key. We just get the primary key
 * from the entity context and cast it to the "known" class.
 *
 * @ejb.interface-method
 * view-type="both"
 *
 * @jboss.method-attributes read-only="true"
 */
 public String getGeneratedPrimaryKey() {
 return (String) entityContext.getPrimaryKey();
 }
}



      • 3207 Views
      • Tags:
        • 1. Re: Performance issue , 2 local String getXXX(32Byte) take
          jamesstrachan
          jamesstrachan Aug 4, 2004 12:09 PM (in response to crowse)

          If we take out the timing code, what you are doing is :-


          For each entry in index {
 Get entity bean for index
 Get ID
 Get value
 }



          Getting the entity bean involves network I/O, and also requires that the server works to create the Entity Bean and to load its data from the database.

          Getting the ID is another operation and also requires the server to activate the EJB.

          Getting the value is another operation across the network and requires another activation on the EJB.

          Each of the three operations has to go through the server layers that deal with security, transaction management etc., and then, as it's CMP, check whether any data has been changed and should be written back to the DB.

          If you are using commit options B or C, the server may also be reloading the entity bean from the database on each method call.

          So the server is really doing quite well to average 30 milliseconds for each operation.

          You can get some improvement by using the getValue() method that you have already written. That will eliminate one network call for each iteration.

          In order to solve the problem, you will need to remove the multiple calls from client to server.

          I attach a method from a stateless session bean that locates EJB's from within the server, extracts data and then returns a List of Data Transfer objects to the client. 

           /**
 * This method retrieves a list of all Sequences from which the user
 * can select. These are obtained from the underlying Entity Beans.
 * <p>
 * The findAll method returns a collection of proxies which can be converted
 * to SequenceNumberRemote objects. The data from these is then unpacked
 * to create SequenceNumberSummary objects.
 * <p>
 * We could avoid this work by returning the Collection of proxies to
 * the Client, which would then call methods on the proxies to get data from
 * the Entity Beans. This would greatly increase the number of network calls
 * and the volume of network trafic. So it's worth writing a few lines of
 * code to aid efficiency.
 * @return ArrayList of SequenceNumberSummary objects.
 * @throws RemoteException
 * @throws FinderException
 */
 public ArrayList getSummary() throws RemoteException, FinderException {

 Collection workingSet;
 SequenceNumberRemote tempBean;
 SequenceNumberSummary temp;
 ArrayList result = new ArrayList();

 logger.info( "getSummary" );

 try {
 workingSet = getHome().findAll();
 }
 catch ( NamingException ne ) {
 logger.error( ne.getMessage(), ne );
 throw new RemoteException( "Name lookup failed" );
 }

 Iterator it = workingSet.iterator();

 // Work through the list of proxies building a SequenceNumberSummary
 // object for each entry in the Collection. Add the object to the ArrayList.
 while( it.hasNext() ) {
 tempBean = (SequenceNumberRemote) it.next();
 temp = new SequenceNumberSummary();
 temp.setSequenceId( tempBean.getSequenceControl().getSequenceId() );
 temp.setSequenceDescription( tempBean.getSequenceControl().getSequenceDescription() );
 temp.setLastUsedValue( tempBean.getLastUsedNumber() );
 result.add( temp );
 }

 return result;

 }

          This should work better as the network I/O is greatly reduced, and the reads from the entity bean are now local. JBoss will also optimise these calls to pass-by-reference instead of pass-by-value.

          This solution may still not be fast enough as the server has to create and juggle 30,000 instances of the Entity Beans. You may need, as you have already guessed, to use JDBC directly to get acceptable performance.

          James Strachan


            • Actions
          • 2. Re: Performance issue , 2 local String getXXX(32Byte) take
            crowse
            crowse Aug 4, 2004 3:26 PM (in response to crowse)

            Hi James,
            Thanks for the tips and explanation, they help greatly.

            As you have noticed, I have already tried both the value bean and SLSB approaches with limited improvement in performance. I even had a method that packed the strings together with a pipe | separator. Yes it was faster but less flexible and maintainable.

            I really would have thought that the read-only tags should turn off a lot of the intermediate layer locking, dirty bit etc. Security, I would have thought, would only happen once at the query or 'record' level, a R/O bean could then be returned in toto.

            I have implemented the JDBC route, and have no performace problems. there (the Action completes in seconds).

            Many thanks, anyway, I now wont go barking up the wrong tree.


            Chris

              • Actions