Since no one tries to crack the puzzle, i will give some more information.
Through our speed-testing we are seeing more strange behaviors.
It seems as JBoss looses the reference to an object if you speed-clicks.
This can only mean that the problems occurs because the same session is
trying to access the same object more than once.
The scenario again:
Session A loads page 1
page 1 initializes and starts
page 1 traverse the lists etc.
page 1 closes all db connections etc.
Now if you click to reload the page before it finishes this happens:
Session A loads page 1
page 1 initializes and starts
page 1 traverse the lists etc. Session A loads page 1 again!
page 1 initializes
page 1 traverse the lists etc.
*page 1 tries to close all db connections etc.
page 1 closes all db-connections.
* This fails ! Could it be that the reference from the JSP->bean->stateless
session bean fails because the same session makes 2 reference to the same
object ? (This must be a bug!)
My collegue argues that in theory we can not be 100% sure that the reference
we get to a stateless session bean is the same when we start a "transaction"
(starts the page) - as the one we have at the end of the transaction.
If this is the case, how can we make sure this is the case ?
This is most likely to occur in heavy-load systems, and i guess most
stress-test systems to not test for the correct result !?
Please help us out here!!!
- Ren� Nygaard
> -----Original Message-----
> From: [EMAIL PROTECTED]
> [mailto:[EMAIL PROTECTED]]
> Sent: 20. april 2001 10:45
> To: [EMAIL PROTECTED]
> Subject: [JBoss-user] problems with speed-clicking. The "handle" to the
> JBoss session bean is lost or refreshed!
>
>
> Hello again JBoss people.
>
> Our "e-mall" is almost ready for consumers.
> The first test-stores are on-line and making test's to the system.
> Our own tests are also running fine, we make small progress every day,
> getting more experience with JBoss and the EJB concept.
> We do however have one question -
> We are using a resultset to select items from the mall to the customer.
> At first we had a SQLManager object inside JBoss which made the
> select-statement, remembered the resultset, and we called
> nextRecord etc. on
> this object. This is really slow, but is very generel, and easy to use.
> So - the first optimization step was to return the resultset to the bean,
> and let the bean traverse the resultset.
> This made the select much faster, and currently we are using this feature.
> BUT - we noticed that when we force the browser to load pages before the
> last one finished, the DBpool is drained. The code that should return the
> connection to the pool is never called.
> After studying our log-files, we notice that the connection from
> the bean to
> the JBoss stateless session bean.
> Here are the log files with comments:
>
> The number in () is a bean-id so we can follow this bean through
> the system.
> this section is a "good" example
> 10:21:05,307 DEBUG JSP:ShowItems - (987754865307) Will get webData
> 10:21:05,307 DEBUG ItemPriceBean - (beanId=987754865307)
> getWebDataByCategoryAndStore(13,null)
> 10:21:05,397 DEBUG ItemPriceBean - (beanId=987754865307) Successfully
> got ref to itemPriceDAOEJB
> 10:21:05,407 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307)
> selectResultSet - Start
> 10:21:05,407 INFO root InterBaseDB - No transaction right now.
> 10:21:05,407 INFO root InterBaseDB - Pool InterBaseDB [1/1/10] gave out
> pooled object:
> org.opentools.minerva.jdbc.xa.wrapper.XAConnectionImpl@45f743
> 10:21:05,407 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307) Got
> 'java:comp/env/jdbc/DBPool' handle
> 10:21:05,407 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307) Did
> _conn.createStatement()
> 10:21:05,407 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307)
> selectResultSet - Did initDB
> 10:21:05,417 INFO ItemPriceDAOEJBBean -
> (beanId=987754865307) Executing
> query...: SELECT NAME, ITEMID, PRICE, PICTURE, STOREID, DESCRIPTION FROM
> ITEMPRICEEJB WHERE CATEGORYID = 13 AND STOREID = 'null' AND NAME !=''
> 10:21:06,078 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307)
> selectResultSet - Did query....returning
> 10:21:06,078 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307) --All
> closed!-- (context that is!)
> 10:21:06,078 DEBUG ItemPriceBean - (beanId=987754865307) Time to fetch
> data (JavaBean layer): 671
> 10:21:06,088 DEBUG ItemPriceBean - (beanId=987754865307) retrieved 6
> items
> 10:21:06,088 DEBUG JSP:ShowItems - (987754865307) Time to fetch data
> (JSP layer): 781
> 10:21:06,088 DEBUG JSP:ShowItems - (987754865307)
> itemprice.gotoNextItem()
> 10:21:06,088 DEBUG JSP:ShowItems - (987754865307)
> itemprice.gotoNextItem() proceed=false
> 10:21:06,088 DEBUG JSP:ShowItems - (987754865307)
> itemprice.gotoNextItem() closeSelect
> 10:21:06,088 DEBUG ItemPriceBean - (beanId=987754865307) Closing
> resultset
> 10:21:06,088 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307) Close
> resultSet???
> 10:21:06,088 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307) please
> Close resultSet
> 10:21:06,088 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307) Close
> statement???
> 10:21:06,088 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307) please
> Close statement
> 10:21:06,088 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307) Close
> Connection???
> 10:21:06,088 DEBUG ItemPriceDAOEJBBean - (beanId=987754865307) please
> Close connection
> 10:21:06,088 INFO root InterBaseDB - Pool InterBaseDB [0/1/10] returned
> object
> org.opentools.minerva.jdbc.xa.wrapper.XAConnectionImpl@45f743 to the
> pool.
> 10:21:06,088 DEBUG JSP:ShowItems - (987754865307)
> itemprice.gotoNextItem() closeSelect - done
>
> So - all it did finish OK!
>
> The next scenario is when is click the same category so quickly that the
> first cycle is not finished.
>
> 10:21:26,858 DEBUG JSP:ShowItems - (987754886858) Store not defined,
> will only get data based on category
> 10:21:26,878 DEBUG JSP:ShowItems - (987754886858) Will get webData
> 10:21:26,878 DEBUG ItemPriceBean - (beanId=987754886858)
> getWebDataByCategoryAndStore(29,-1)
> 10:21:26,898 DEBUG ItemPriceBean - (beanId=987754886858) Successfully
> got ref to itemPriceDAOEJB
> 10:21:26,898 DEBUG ItemPriceDAOEJBBean - (beanId=987754886858)
> selectResultSet - Start
> 10:21:26,908 INFO root InterBaseDB - No transaction right now.
> 10:21:26,908 INFO root InterBaseDB - Pool InterBaseDB [1/1/10] gave out
> pooled object:
> org.opentools.minerva.jdbc.xa.wrapper.XAConnectionImpl@45f743
> 10:21:26,908 DEBUG ItemPriceDAOEJBBean - (beanId=987754886858) Got
> 'java:comp/env/jdbc/DBPool' handle
> 10:21:26,908 DEBUG ItemPriceDAOEJBBean - (beanId=987754886858) Did
> _conn.createStatement()
> 10:21:26,908 DEBUG ItemPriceDAOEJBBean - (beanId=987754886858)
> selectResultSet - Did initDB
> 10:21:26,908 INFO ItemPriceDAOEJBBean -
> (beanId=987754886858) Executing
> query...: SELECT NAME, ITEMID, PICTURE, STOREID, DESCRIPTION FROM
> ITEMPRICEEJB WHERE CATEGORYID = 29 AND NAME !=''
> 10:21:26,948 DEBUG ItemPriceDAOEJBBean - (beanId=987754886858)
> selectResultSet - Did query....returning
> 10:21:26,948 DEBUG ItemPriceDAOEJBBean - (beanId=987754886858) --All
> closed!-- (This is the context used to get the connection)
> 10:21:26,948 DEBUG ItemPriceBean - (beanId=987754886858) Time to fetch
> data (JavaBean layer): 50
> 10:21:26,948 DEBUG ItemPriceBean - (beanId=987754886858) retrieved 5
> items
> 10:21:26,948 DEBUG JSP:ShowItems - (987754886858) Time to fetch data
> (JSP layer): 70
> 10:21:26,948 DEBUG JSP:ShowItems - (987754886858)
> itemprice.gotoNextItem()
> 10:21:26,948 DEBUG JSP:ShowItems - (987754886858)
> itemprice.gotoNextItem() proceed=true
> //Here the next "click" starts! (Now we got the ..858 and the
> ..429 running!
> 10:21:27,439 DEBUG JSP:ShowItems - (987754887429) Store not defined,
> will only get data based on category
> 10:21:27,469 DEBUG JSP:ShowItems - (987754887429) Will get webData
> 10:21:27,479 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429)
> selectResultSet - Start
> //The first one is finished!
> 10:21:27,759 DEBUG JSP:ShowItems - (987754886858)
> itemprice.gotoNextItem() done while statement - end the jsp page!
> 10:21:27,759 DEBUG JSP:ShowItems - (987754886858)
> itemprice.gotoNextItem() closeSelect
> 10:21:27,759 DEBUG ItemPriceBean - (beanId=987754886858) Closing
> resultset
>
> //Here is get's strange. The beanId is gone - meaning is it a new
> ItemPriceDAOEJBBean object.
>
> 10:21:27,759 DEBUG ItemPriceDAOEJBBean - () Close resultSet???
> 10:21:27,759 DEBUG ItemPriceDAOEJBBean - () resultSet == null
> 10:21:27,759 DEBUG ItemPriceDAOEJBBean - () Close statement???
> 10:21:27,759 DEBUG ItemPriceDAOEJBBean - () statement == null
> 10:21:27,759 DEBUG ItemPriceDAOEJBBean - () Close Connection???
> 10:21:27,759 DEBUG ItemPriceDAOEJBBean - () connection == null
> 10:21:27,759 DEBUG JSP:ShowItems - (987754886858)
> itemprice.gotoNextItem() closeSelect - done
>
> I put the next part of the log-file in here to show that the ...429 is
> closing normally even when a new cycle is starting.
>
> The useBean statement in our JSP is Request (we also had a
> session to try it
> out!)
> The ItemPriceDAOEJBBean is a stateless session bean.
>
> Can anyone explain why this goes wrong ?
> AND please do not say : "dont do it like that!".
>
> We are running JBoss 2.2
> Jetty 3.1 RC 2
> Interbase 6
> W2K host
>
>
> ------------rest of log------------------
>
> 10:21:28,120 DEBUG JSP:ShowItems - (987754888120) Store not defined,
> will only get data based on category
> 10:21:28,120 DEBUG JSP:ShowItems - (987754888120) Will get webData
> 10:21:28,120 DEBUG ItemPriceBean - (beanId=987754888120)
> getWebDataByCategoryAndStore(29,-1)
> 10:21:28,130 DEBUG ItemPriceBean - (beanId=987754888120) Successfully
> got ref to itemPriceDAOEJB
> 10:21:28,130 DEBUG ItemPriceDAOEJBBean - (beanId=987754888120)
> selectResultSet - Start
> 10:21:28,710 DEBUG JSP:ShowItems - (987754888710) Store not defined,
> will only get data based on category
> 10:21:28,710 DEBUG JSP:ShowItems - (987754888710) Will get webData
> 10:21:28,710 DEBUG ItemPriceBean - (beanId=987754888710)
> getWebDataByCategoryAndStore(29,-1)
> 10:21:28,741 DEBUG ItemPriceBean - (beanId=987754888710) Successfully
> got ref to itemPriceDAOEJB
> 10:21:28,741 DEBUG ItemPriceDAOEJBBean - (beanId=987754888710)
> selectResultSet - Start
> 10:21:28,761 INFO root InterBaseDB -
> org.opentools.minerva.jdbc.xa.wrapper.XADataSourceImpl created new
> Connection (interbase.interclient.Connection) with XAResource
> org.opentools.minerva.jdbc.xa.wrapper.XAResourceImpl and XAConnection
> org.opentools.minerva.jdbc.xa.wrapper.XAConnectionImpl.
> 10:21:28,761 INFO root InterBaseDB - No transaction right now.
> 10:21:28,761 INFO root InterBaseDB - Pool InterBaseDB [1/1/10]
> gave out new
> object: org.opentools.minerva.jdbc.xa.wrapper.XAConnectionImpl@61fcdd
> 10:21:28,771 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429) Got
> 'java:comp/env/jdbc/DBPool' handle
> 10:21:28,771 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429) Did
> _conn.createStatement()
> 10:21:28,771 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429)
> selectResultSet - Did initDB
> 10:21:28,771 INFO ItemPriceDAOEJBBean -
> (beanId=987754887429) Executing
> query...: SELECT NAME, ITEMID, PICTURE, STOREID, DESCRIPTION FROM
> ITEMPRICEEJB WHERE CATEGORYID = 29 AND NAME !=''
> 10:21:28,951 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429)
> selectResultSet - Did query....returning
> 10:21:28,951 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429) --All
> closed!--
> 10:21:28,951 DEBUG ItemPriceBean - (beanId=987754887429) Time to fetch
> data (JavaBean layer): 1472
> 10:21:28,951 DEBUG ItemPriceBean - (beanId=987754887429) retrieved 5
> items
> 10:21:28,951 DEBUG JSP:ShowItems - (987754887429) Time to fetch data
> (JSP layer): 1502
> 10:21:28,951 DEBUG JSP:ShowItems - (987754887429)
> itemprice.gotoNextItem() Used as itemPrice.first() because jdbc driver is
> not 2.0 compliant
> 10:21:28,951 DEBUG JSP:ShowItems - (987754887429)
> itemprice.gotoNextItem() proceed=true
> 10:21:29,161 DEBUG JSP:ShowItems - (987754887429)
> itemprice.gotoNextItem() done while statement - end the jsp page!
> 10:21:29,161 DEBUG JSP:ShowItems - (987754887429)
> itemprice.gotoNextItem() closeSelect
> 10:21:29,161 DEBUG ItemPriceBean - (beanId=987754887429) Closing
> resultset
> 10:21:29,161 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429) Close
> resultSet???
> 10:21:29,161 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429) please
> Close resultSet
> 10:21:29,161 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429) Close
> statement???
> 10:21:29,161 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429) please
> Close statement
> 10:21:29,161 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429) Close
> Connection???
> 10:21:29,161 DEBUG ItemPriceDAOEJBBean - (beanId=987754887429) please
> Close connection
> 10:21:29,171 INFO root InterBaseDB - Pool InterBaseDB [1/2/10] returned
> object
> org.opentools.minerva.jdbc.xa.wrapper.XAConnectionImpl@61fcdd to the
> pool.
> 10:21:29,171 DEBUG JSP:ShowItems - (987754887429)
> itemprice.gotoNextItem() closeSelect - done
>
> - Ren� Rolander Nygaard
>
>
winmail.dat
