I have turned on the instance per transaction on userLocal, I have also turned on the trace:
Here is a partial log. 2004-06-15 15:04:58,566 204304 INFO [STDOUT] (http-0.0.0.0-8080-Processor25:) 15/06/2004 15:04:58 com.matrix.framework.ip.controller.UserController getSingleNotByPrimaryKey | FINEST: ===============User Id = 'user' Password = '1' ======================= | 2004-06-15 15:04:58,566 204304 TRACE [org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor] (http-0.0.0.0-8080-Processor25:) invokerBInding is null in ProxyFactoryFinder | 2004-06-15 15:04:58,586 204324 TRACE [org.jboss.ejb.plugins.LogInterceptor] (http-0.0.0.0-8080-Processor25:) Start method=findByUserNameAndPassword | 2004-06-15 15:04:58,586 204324 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) Current transaction in MI is TransactionImpl:XidImpl [FormatId=257, GlobalId=norman//15, BranchQual=] | 2004-06-15 15:04:58,586 204324 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) TX_REQUIRED for findByUserNameAndPassword timeout=0 | 2004-06-15 15:04:58,586 204324 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) Thread came in with tx TransactionImpl:XidImpl [FormatId=257, GlobalId=norman//15, BranchQual=] | 2004-06-15 15:04:58,586 204324 TRACE [org.jboss.ejb.plugins.EntityInstancePool] (http-0.0.0.0-8080-Processor25:) Get instance [EMAIL PROTECTED] com.matrix.framework.ip.model.UserBean | 2004-06-15 15:04:58,606 204344 DEBUG [org.jboss.ejb.plugins.cmp.jdbc.JDBCEJBQLQuery.User#findByUserNameAndPassword] (http-0.0.0.0-8080-Processor25:) Executing SQL: SELECT DISTINCT t0_a.ID, t0_a.USER_NAME, t0_a.START_DATE, t0_a.END_DATE, t0_a.CREATE_DATE, t0_a.UPDATE_DATE, t0_a.TIME_STAMP, t0_a.CREATOR_USER_ID, t0_a.UPDATOR_USER_ID, t0_a.VERSION, t0_a.IS_OBSOLETE, t0_a.ORGANIZATION_ID, t0_a.PERSON_ID FROM EMI_USER t0_a WHERE (t0_a.USER_NAME = ? AND t0_a.USER_PASSWORD = ?) | 2004-06-15 15:04:58,606 204344 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] (http-0.0.0.0-8080-Processor25:) supplying ManagedConnection from pool: [EMAIL PROTECTED] [EMAIL PROTECTED] handles=0 lastUse=1087304638189 permit=false trackByTx=false [EMAIL PROTECTED] [EMAIL PROTECTED] | 2004-06-15 15:04:58,606 204344 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] (http-0.0.0.0-8080-Processor25:) Getting connection from pool [EMAIL PROTECTED] [EMAIL PROTECTED] handles=0 lastUse=1087304638189 permit=true trackByTx=true [EMAIL PROTECTED] [EMAIL PROTECTED] [InUse/Available/Max]: [1/19/20] | 2004-06-15 15:04:58,656 204394 TRACE [org.jboss.ejb.plugins.cmp.jdbc.JDBCEJBQLQuery.User#findByUserNameAndPassword] (http-0.0.0.0-8080-Processor25:) Set parameter: index=1, jdbcType=VARCHAR, value=user | 2004-06-15 15:04:58,656 204394 TRACE [org.jboss.ejb.plugins.cmp.jdbc.JDBCEJBQLQuery.User#findByUserNameAndPassword] (http-0.0.0.0-8080-Processor25:) Set parameter: index=2, jdbcType=VARCHAR, value=1 | 2004-06-15 15:04:58,867 204605 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=userName | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=startDate | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=endDate | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=createDate | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=updateDate | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=timeStamp | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=creatorUserId | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=updatorUserId | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=version | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=isObsolete | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=id | 2004-06-15 15:04:58,877 204615 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Add preload data: entity=User pk=22 field=id | 2004-06-15 15:04:58,897 204635 TRACE [org.jboss.ejb.plugins.EntityInstancePool] (http-0.0.0.0-8080-Processor25:) 0/100 Free instance:[EMAIL PROTECTED] com.matrix.framework.ip.model.UserBean | 2004-06-15 15:04:58,897 204635 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) TxInterceptorCMT: In finally | 2004-06-15 15:04:58,897 204635 TRACE [org.jboss.ejb.plugins.LogInterceptor] (http-0.0.0.0-8080-Processor25:) End method=findByUserNameAndPassword | 2004-06-15 15:04:58,907 204645 INFO [STDOUT] (http-0.0.0.0-8080-Processor25:) 15/06/2004 15:04:58 com.matrix.framework.infrastructure.controller.InnerBasicController getSingleTO | INFO: in InnerBasicController.getSingleTO after finding beanLocal. | 2004-06-15 15:04:59,087 204825 TRACE [org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor] (http-0.0.0.0-8080-Processor25:) invokerBInding is null in ProxyFactoryFinder | 2004-06-15 15:04:59,087 204825 TRACE [org.jboss.ejb.plugins.LogInterceptor] (http-0.0.0.0-8080-Processor25:) Start method=getId | 2004-06-15 15:04:59,087 204825 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) Current transaction in MI is TransactionImpl:XidImpl [FormatId=257, GlobalId=norman//15, BranchQual=] | 2004-06-15 15:04:59,087 204825 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) TX_NOT_SUPPORTED for getId | 2004-06-15 15:04:59,087 204825 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) Thread came in with tx TransactionImpl:XidImpl [FormatId=257, GlobalId=norman//15, BranchQual=] | 2004-06-15 15:04:59,087 204825 TRACE [org.jboss.ejb.plugins.EntityLockInterceptor] (http-0.0.0.0-8080-Processor25:) Begin invoke, key=22 | 2004-06-15 15:04:59,097 204835 TRACE [org.jboss.ejb.plugins.EntityInstancePool] (http-0.0.0.0-8080-Processor25:) Get instance [EMAIL PROTECTED] com.matrix.framework.ip.model.UserBean | 2004-06-15 15:04:59,117 204855 TRACE [org.jboss.ejb.plugins.EntityInstanceInterceptor] (http-0.0.0.0-8080-Processor25:) Begin invoke, key=22 | 2004-06-15 15:04:59,117 204855 TRACE [org.jboss.ejb.plugins.EntitySynchronizationInterceptor] (http-0.0.0.0-8080-Processor25:) invoke called for ctx User#22, tx=null | 2004-06-15 15:04:59,117 204855 TRACE [org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreManager.User] (http-0.0.0.0-8080-Processor25:) RESET PERSISTENCE CONTEXT: id=22 | 2004-06-15 15:04:59,127 204865 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) load data: entity=User pk=22 | 2004-06-15 15:04:59,127 204865 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) No preload data found: entity=User pk=22 | 2004-06-15 15:04:59,137 204875 TRACE [org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCEntityBridge.User] (http-0.0.0.0-8080-Processor25:) Default eager-load for entity: readahead=null | 2004-06-15 15:04:59,147 204885 DEBUG [org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.User] (http-0.0.0.0-8080-Processor25:) Executing SQL: SELECT SIGNATURE, USER_PASSWORD, USER_NAME, START_DATE, END_DATE, CREATE_DATE, UPDATE_DATE, TIME_STAMP, CREATOR_USER_ID, UPDATOR_USER_ID, VERSION, IS_OBSOLETE, MANAGER_USER_ID, ORGANIZATION_ID, PERSON_ID FROM EMI_USER WHERE (ID=?) | 2004-06-15 15:05:00,539 206277 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] (http-0.0.0.0-8080-Processor25:) supplying new ManagedConnection: [EMAIL PROTECTED] [EMAIL PROTECTED] handles=0 lastUse=1087304700539 permit=false trackByTx=false [EMAIL PROTECTED] [EMAIL PROTECTED] | 2004-06-15 15:05:00,539 206277 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] (http-0.0.0.0-8080-Processor25:) Getting connection from pool [EMAIL PROTECTED] [EMAIL PROTECTED] handles=0 lastUse=1087304700539 permit=true trackByTx=false [EMAIL PROTECTED] [EMAIL PROTECTED] [InUse/Available/Max]: [2/18/20] | 2004-06-15 15:05:00,539 206277 TRACE [org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMP2xFieldBridge.User#id] (http-0.0.0.0-8080-Processor25:) Set parameter: index=1, jdbcType=BIGINT, value=22 | 2004-06-15 15:05:00,719 206457 TRACE [org.jboss.ejb.plugins.cmp.jdbc.JDBCUtil] (http-0.0.0.0-8080-Processor25:) Get result: index=1, javaType=[B, Big Binary, value=null | 2004-06-15 15:05:00,719 206457 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] (http-0.0.0.0-8080-Processor25:) putting ManagedConnection back into pool kill=false [EMAIL PROTECTED] [EMAIL PROTECTED] handles=0 lastUse=1087304700539 permit=true trackByTx=false [EMAIL PROTECTED] [EMAIL PROTECTED] | 2004-06-15 15:05:00,719 206457 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] (http-0.0.0.0-8080-Processor25:) Returning connection to pool [EMAIL PROTECTED] [EMAIL PROTECTED] handles=0 lastUse=1087304700719 permit=false trackByTx=false [EMAIL PROTECTED] [EMAIL PROTECTED] [InUse/Available/Max]: [1/19/20] | 2004-06-15 15:05:00,729 206467 WARN [org.jboss.ejb.plugins.PerTxEntityInstanceCache] (http-0.0.0.0-8080-Processor25:) Unable to passivate due to ctx lock, id=22 | 2004-06-15 15:05:00,729 206467 TRACE [org.jboss.ejb.plugins.EntityInstanceInterceptor] (http-0.0.0.0-8080-Processor25:) End invoke, key=22, ctx=User#22 | 2004-06-15 15:05:00,729 206467 TRACE [org.jboss.ejb.plugins.EntityLockInterceptor] (http-0.0.0.0-8080-Processor25:) End invoke, key=22 | 2004-06-15 15:05:00,729 206467 TRACE [org.jboss.ejb.plugins.LogInterceptor] (http-0.0.0.0-8080-Processor25:) End method=getId | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor] (http-0.0.0.0-8080-Processor25:) invokerBInding is null in ProxyFactoryFinder | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.LogInterceptor] (http-0.0.0.0-8080-Processor25:) Start method=getSignature | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) Current transaction in MI is TransactionImpl:XidImpl [FormatId=257, GlobalId=norman//15, BranchQual=] | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) TX_REQUIRED for getSignature timeout=0 | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) Thread came in with tx TransactionImpl:XidImpl [FormatId=257, GlobalId=norman//15, BranchQual=] | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.EntityLockInterceptor] (http-0.0.0.0-8080-Processor25:) Begin invoke, key=22 | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.EntityInstancePool] (http-0.0.0.0-8080-Processor25:) Get instance [EMAIL PROTECTED] com.matrix.framework.ip.model.UserBean | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.EntityInstanceInterceptor] (http-0.0.0.0-8080-Processor25:) Begin invoke, key=22 | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.EntitySynchronizationInterceptor] (http-0.0.0.0-8080-Processor25:) invoke called for ctx User#22, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=norman//15, BranchQual=] | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreManager.User] (http-0.0.0.0-8080-Processor25:) RESET PERSISTENCE CONTEXT: id=22 | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) load data: entity=User pk=22 | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=startDate | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=version | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=userName | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=createDate | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=updatorUserId | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=id | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=endDate | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=isObsolete | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=id | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=creatorUserId | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=timeStamp | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) Preloading data: entity=User pk=22 cmpField=updateDate | 2004-06-15 15:05:00,749 206487 TRACE [org.jboss.ejb.plugins.EntitySynchronizationInterceptor] (http-0.0.0.0-8080-Processor25:) register, ctx=User#22, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=norman//15, BranchQual=] | 2004-06-15 15:05:00,779 206517 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) load data: entity=User pk=22 | 2004-06-15 15:05:00,779 206517 TRACE [org.jboss.ejb.plugins.cmp.jdbc.ReadAheadCache.User] (http-0.0.0.0-8080-Processor25:) No preload data found: entity=User pk=22 | 2004-06-15 15:05:00,779 206517 DEBUG [org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.User] (http-0.0.0.0-8080-Processor25:) Executing SQL: SELECT SIGNATURE FROM EMI_USER WHERE (ID=?) | 2004-06-15 15:05:00,779 206517 TRACE [org.jboss.resource.connectionmanager.JBossManagedConnectionPool] (http-0.0.0.0-8080-Processor25:) Getting connection tracked by transaction [EMAIL PROTECTED] [EMAIL PROTECTED] handles=0 lastUse=1087304638189 permit=true trackByTx=true [EMAIL PROTECTED] [EMAIL PROTECTED] [InUse/Available/Max]: [1/19/20] | 2004-06-15 15:05:00,779 206517 TRACE [org.jboss.ejb.plugins.cmp.jdbc.bridge.JDBCCMP2xFieldBridge.User#id] (http-0.0.0.0-8080-Processor25:) Set parameter: index=1, jdbcType=BIGINT, value=22 | 2004-06-15 15:05:00,950 206688 TRACE [org.jboss.ejb.plugins.cmp.jdbc.JDBCUtil] (http-0.0.0.0-8080-Processor25:) Get result: index=1, javaType=[B, Big Binary, value=null | 2004-06-15 15:05:00,950 206688 TRACE [org.jboss.ejb.plugins.EntitySynchronizationInterceptor] (http-0.0.0.0-8080-Processor25:) register, ctx=User#22, tx=TransactionImpl:XidImpl [FormatId=257, GlobalId=norman//15, BranchQual=] | 2004-06-15 15:05:00,950 206688 TRACE [org.jboss.ejb.plugins.EntityInstanceInterceptor] (http-0.0.0.0-8080-Processor25:) End invoke, key=22, ctx=User#22 | 2004-06-15 15:05:00,950 206688 TRACE [org.jboss.ejb.plugins.EntityLockInterceptor] (http-0.0.0.0-8080-Processor25:) End invoke, key=22 | 2004-06-15 15:05:00,950 206688 TRACE [org.jboss.ejb.plugins.TxInterceptorCMT] (http-0.0.0.0-8080-Processor25:) TxInterceptorCMT: In finally | 2004-06-15 15:05:00,950 206688 TRACE [org.jboss.ejb.plugins.LogInterceptor] (http-0.0.0.0-8080-Processor25:) End method=getSignature There are more lines like that ahead for each getSomething from this bean. I don't understand what's going on. what my application does is after it has the userLocal it copies parameters from this bean into a Transport object (this is why there the getId, getSignature and more like it in the log). This is done within the same transaction. The first thing I don't understand is why jboss selects from the database again each time? It has already selected the stuff on the finder? don't we have cache? View the original post : http://www.jboss.org/index.html?module=bb&op=viewtopic&p=3838772#3838772 Reply to the post : http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&p=3838772 ------------------------------------------------------- This SF.Net email is sponsored by The 2004 JavaOne(SM) Conference Learn from the experts at JavaOne(SM), Sun's Worldwide Java Developer Conference, June 28 - July 1 at the Moscone Center in San Francisco, CA REGISTER AND SAVE! http://java.sun.com/javaone/sf Priority Code NWMGYKND _______________________________________________ JBoss-user mailing list [EMAIL PROTECTED] https://lists.sourceforge.net/lists/listinfo/jboss-user
