You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@geronimo.apache.org by "Matt Hogstrom (JIRA)" <ji...@apache.org> on 2006/12/12 06:53:20 UTC
[jira] Created: (GERONIMO-2649) Insert of new EJB does not appear
to be occurring
Insert of new EJB does not appear to be occurring
--------------------------------------------------
Key: GERONIMO-2649
URL: http://issues.apache.org/jira/browse/GERONIMO-2649
Project: Geronimo
Issue Type: Bug
Security Level: public (Regular issues)
Affects Versions: 1.2, 2.0-M1
Environment: Mac OS X
Reporter: Matt Hogstrom
Assigned To: Gianny Damour
Priority: Blocker
Fix For: 1.2, 2.0-M1
Buy of a stock is not working correctly. It appears that the database insert is not flushing at the right time and this is causing subsequent finders to fail. I have included some tracing here to hopefully isolate the problem. If you could take a look at this perhaps you can shed some light on the problem.
This is against Geronimo 1.2 and the published TranQL 1.4-SNAPSHOT. Please do and svn up of TranQL and build locally. I'll release it tomorrow but my config is hosed tonight.
I'm using daytrader-ear-2.0-SNAPSHOT and the daytrader-jpa-plan.xml located in http://svn.apache.org/repos/asf/geronimo/daytrader/trunk/plans/daytrader-jpa-plan.xml
In the configuration panel choose the option to create the tables. Once this is done populate the tables.
I snipped out the connection mgmt stuff so you'll simply see the JDBC operations.
You can then re-create by following this sequence from the main DayTrader login:
Login to uid:0 (all passwords are xxx)
Select quote operation
Buy a stock
When purchasing a stock a new order is created. However, the actual row does not appear to be flushed to the database and subsequent finds fail. Here is the sequence of events.
{panel:title=Login to uid:0| borderStyle=dashed| borderColor=#ccc| titleBGColor=#F7D6C1| bgColor=#FFFFCE}
23:27:20,576 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
23:27:20,577 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:27:20,578 TRACE [JDBCQueryCommand] 1 were returned.
23:27:20,580 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
23:27:20,581 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:27:20,581 TRACE [JDBCQueryCommand] 1 were returned.
23:27:20,583 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
23:27:20,585 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:27:20,586 TRACE [JDBCQueryCommand] 1 were returned.
23:27:20,588 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID FROM OrderEJB o, AccountEJB T0 WHERE T0.accountID = o.account_accountID AND (o.orderStatus = 'closed' AND T0.accountID = ?)"
23:27:20,588 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:27:20,592 TRACE [JDBCQueryCommand] 0 were returned.
23:27:20,600 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:20 EST 2006------
23:27:20,601 DEBUG [Log] OrderAlertFilter: userID=uid:0 closedOrders=
23:27:20,601 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:20 EST 2006------
23:27:20,601 DEBUG [Log] ---Log.printCollection -- collection size=0
23:27:20,601 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:20 EST 2006------
23:27:20,624 DEBUG [Log] ---Log.printCollection -- complete
23:27:20,624 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:20,627 TRACE [Log] TradeAction:login(uid:0, xxx) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:21,840 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
23:27:21,840 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:27:21,841 TRACE [JDBCQueryCommand] 1 were returned.
23:27:21,844 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
23:27:21,845 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:27:21,847 TRACE [JDBCQueryCommand] 1 were returned.
23:27:21,848 TRACE [Log] TradeBean:login(uid:0, xxx) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:21,849 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
23:27:21,849 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:27:21,850 TRACE [JDBCQueryCommand] 1 were returned.
23:27:21,851 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.profile_userID FROM AccountEJB T WHERE T.accountID = ?"
23:27:21,851 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:27:21,852 TRACE [JDBCQueryCommand] 1 were returned.
23:27:21,854 TRACE [Log] TradeBean:login(uid:0,xxx) success
Account Data for account: 0
loginCount:8
logoutCount:0
lastLogin:2006-12-11 23:27:21.854
creationDate:2006-12-11 20:57:22.969
balance:969223.15
openBalance:1000000.00
profileID:uid:0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
{color:red} The following interaction concerns me as the parm values and the parameter markers seem backwards: {color}
23:27:21,856 TRACE [JDBCUpdateCommand] Prepared SQL Statement="UPDATE AccountEJB SET lastLogin = ?, loginCount = ? WHERE accountID = ?"
23:27:21,856 TRACE [JDBCUpdateCommand] Setting parm[0]=0
23:27:21,856 TRACE [JDBCUpdateCommand] Setting parm[1]=969223.15
23:27:21,857 TRACE [JDBCUpdateCommand] Setting parm[2]=2006-12-11 20:57:22.969
23:27:21,909 TRACE [Log] TradeAction:getAccountData(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:21,911 TRACE [Log] TradeBean:getAccountData(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:23,080 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
23:27:23,080 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:27:23,082 TRACE [JDBCQueryCommand] 1 were returned.
23:27:23,083 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
23:27:23,083 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:27:23,087 TRACE [JDBCQueryCommand] 1 were returned.
23:27:23,089 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
23:27:23,089 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:27:23,091 TRACE [JDBCQueryCommand] 1 were returned.
23:27:23,095 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.profile_userID FROM AccountEJB T WHERE T.accountID = ?"
23:27:23,095 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:27:23,096 TRACE [JDBCQueryCommand] 1 were returned.
23:27:23,107 TRACE [Log] TradeAction:getHoldings(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:23,108 TRACE [Log] TradeBean:getHoldings(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:23,110 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT h.holdingID, h.purchaseDate, h.purchasePrice, h.quantity FROM HOLDINGEJB h, AccountEJB T0, AccountProfileEJB T1 WHERE T0.accountID = h.account_accountID AND T1.userID = T0.profile_userID AND (T1.userID = ?)"
23:27:23,110 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:27:23,159 TRACE [JDBCQueryCommand] 3 were returned.
23:27:23,161 TRACE [Log] Got holdings collection size=3 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:23,164 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.quote_symbol FROM HOLDINGEJB T WHERE T.holdingID = ?"
23:27:23,165 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:27:23,165 TRACE [JDBCQueryCommand] 1 were returned.
23:27:23,167 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.quote_symbol FROM HOLDINGEJB T WHERE T.holdingID = ?"
23:27:23,167 TRACE [JDBCQueryCommand] Setting parm[0] 1
23:27:23,168 TRACE [JDBCQueryCommand] 1 were returned.
23:27:23,170 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.quote_symbol FROM HOLDINGEJB T WHERE T.holdingID = ?"
23:27:23,170 TRACE [JDBCQueryCommand] Setting parm[0] 2
23:27:23,171 TRACE [JDBCQueryCommand] 1 were returned.
23:27:23,192 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:23,193 TRACE [Log] TradeAction:getMarketSummary() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:23,193 TRACE [Log] TradeBean:getMarketSummary -- getting market summary threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:23,194 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT q.symbol, q.change1, q.companyName, q.high, q.low, q.open1, q.price, q.volume FROM QuoteEJB q WHERE (q.symbol LIKE 's:1__') ORDER BY q.change1 DESC"
23:27:23,283 TRACE [JDBCQueryCommand] 100 were returned.
{panel}
{panel:title=Now Clicking on Get Quotes| borderStyle=dashed| borderColor=#ccc| titleBGColor=#F7D6C1| bgColor=#FFFFCE}
23:27:46,296 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
23:27:46,297 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:27:46,298 TRACE [JDBCQueryCommand] 1 were returned.
23:27:46,302 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
23:27:46,302 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:27:46,304 TRACE [JDBCQueryCommand] 1 were returned.
23:27:46,307 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
23:27:46,307 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:27:46,309 TRACE [JDBCQueryCommand] 1 were returned.
23:27:46,311 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID FROM OrderEJB o, AccountEJB T0 WHERE T0.accountID = o.account_accountID AND (o.orderStatus = 'closed' AND T0.accountID = ?)"
23:27:46,311 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:27:46,313 TRACE [JDBCQueryCommand] 0 were returned.
23:27:46,316 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:46 EST 2006------
23:27:46,317 DEBUG [Log] OrderAlertFilter: userID=uid:0 closedOrders=
23:27:46,317 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:46 EST 2006------
23:27:46,319 DEBUG [Log] ---Log.printCollection -- collection size=0
23:27:46,330 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:46 EST 2006------
23:27:46,330 DEBUG [Log] ---Log.printCollection -- complete
23:27:46,330 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:46,334 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:46,342 TRACE [Log] TradeAction:getQuote(s:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:46,342 TRACE [Log] TradeBean:getQuote(s:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:48,264 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:48,264 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:27:48,267 TRACE [JDBCQueryCommand] 1 were returned.
23:27:48,277 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:48,277 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:27:48,278 TRACE [JDBCQueryCommand] 1 were returned.
23:27:48,280 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:48,281 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:27:48,282 TRACE [JDBCQueryCommand] 1 were returned.
23:27:48,283 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:48,283 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:27:48,284 TRACE [JDBCQueryCommand] 1 were returned.
23:27:48,285 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:48,285 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:27:48,286 TRACE [JDBCQueryCommand] 1 were returned.
23:27:48,288 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:48,288 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:27:48,290 TRACE [JDBCQueryCommand] 1 were returned.
23:27:48,291 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:48,291 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:27:48,292 TRACE [JDBCQueryCommand] 1 were returned.
23:27:48,294 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:48,294 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:27:48,295 TRACE [JDBCQueryCommand] 1 were returned.
23:27:48,354 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:48,357 TRACE [Log] TradeAction:getQuote(s:1) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:48,357 TRACE [Log] TradeBean:getQuote(s:1) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:49,211 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:49,211 TRACE [JDBCQueryCommand] Setting parm[0] s:1
23:27:49,212 TRACE [JDBCQueryCommand] 1 were returned.
23:27:49,214 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:49,214 TRACE [JDBCQueryCommand] Setting parm[0] s:1
23:27:49,215 TRACE [JDBCQueryCommand] 1 were returned.
23:27:49,216 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:49,216 TRACE [JDBCQueryCommand] Setting parm[0] s:1
23:27:49,217 TRACE [JDBCQueryCommand] 1 were returned.
23:27:49,219 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:49,219 TRACE [JDBCQueryCommand] Setting parm[0] s:1
23:27:49,220 TRACE [JDBCQueryCommand] 1 were returned.
23:27:49,221 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:49,221 TRACE [JDBCQueryCommand] Setting parm[0] s:1
23:27:49,222 TRACE [JDBCQueryCommand] 1 were returned.
23:27:49,224 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:49,224 TRACE [JDBCQueryCommand] Setting parm[0] s:1
23:27:49,225 TRACE [JDBCQueryCommand] 1 were returned.
23:27:49,226 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:49,227 TRACE [JDBCQueryCommand] Setting parm[0] s:1
23:27:49,227 TRACE [JDBCQueryCommand] 1 were returned.
23:27:49,229 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:49,229 TRACE [JDBCQueryCommand] Setting parm[0] s:1
23:27:49,229 TRACE [JDBCQueryCommand] 1 were returned.
23:27:49,276 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:49,277 TRACE [Log] TradeAction:getQuote(s:2) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:49,277 TRACE [Log] TradeBean:getQuote(s:2) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:50,178 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:50,178 TRACE [JDBCQueryCommand] Setting parm[0] s:2
23:27:50,179 TRACE [JDBCQueryCommand] 1 were returned.
23:27:50,181 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:50,181 TRACE [JDBCQueryCommand] Setting parm[0] s:2
23:27:50,181 TRACE [JDBCQueryCommand] 1 were returned.
23:27:50,183 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:50,183 TRACE [JDBCQueryCommand] Setting parm[0] s:2
23:27:50,335 TRACE [JDBCQueryCommand] 1 were returned.
23:27:50,336 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:50,336 TRACE [JDBCQueryCommand] Setting parm[0] s:2
23:27:50,337 TRACE [JDBCQueryCommand] 1 were returned.
23:27:50,339 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:50,339 TRACE [JDBCQueryCommand] Setting parm[0] s:2
23:27:50,340 TRACE [JDBCQueryCommand] 1 were returned.
23:27:50,341 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:50,341 TRACE [JDBCQueryCommand] Setting parm[0] s:2
23:27:50,341 TRACE [JDBCQueryCommand] 1 were returned.
23:27:50,484 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:50,484 TRACE [JDBCQueryCommand] Setting parm[0] s:2
23:27:50,485 TRACE [JDBCQueryCommand] 1 were returned.
23:27:50,486 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:50,486 TRACE [JDBCQueryCommand] Setting parm[0] s:2
23:27:50,486 TRACE [JDBCQueryCommand] 1 were returned.
23:27:50,499 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:50,501 TRACE [Log] TradeAction:getQuote(s:3) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:50,501 TRACE [Log] TradeBean:getQuote(s:3) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:52,480 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:52,481 TRACE [JDBCQueryCommand] Setting parm[0] s:3
23:27:52,483 TRACE [JDBCQueryCommand] 1 were returned.
23:27:52,485 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:52,485 TRACE [JDBCQueryCommand] Setting parm[0] s:3
23:27:52,486 TRACE [JDBCQueryCommand] 1 were returned.
23:27:52,488 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:52,489 TRACE [JDBCQueryCommand] Setting parm[0] s:3
23:27:52,489 TRACE [JDBCQueryCommand] 1 were returned.
23:27:52,492 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:52,492 TRACE [JDBCQueryCommand] Setting parm[0] s:3
23:27:52,493 TRACE [JDBCQueryCommand] 1 were returned.
23:27:52,495 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:52,495 TRACE [JDBCQueryCommand] Setting parm[0] s:3
23:27:52,496 TRACE [JDBCQueryCommand] 1 were returned.
23:27:52,498 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:52,498 TRACE [JDBCQueryCommand] Setting parm[0] s:3
23:27:52,499 TRACE [JDBCQueryCommand] 1 were returned.
23:27:52,500 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:52,500 TRACE [JDBCQueryCommand] Setting parm[0] s:3
23:27:52,501 TRACE [JDBCQueryCommand] 1 were returned.
23:27:52,502 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:52,502 TRACE [JDBCQueryCommand] Setting parm[0] s:3
23:27:52,503 TRACE [JDBCQueryCommand] 1 were returned.
23:27:52,514 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:52,517 TRACE [Log] TradeAction:getQuote(s:4) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:52,518 TRACE [Log] TradeBean:getQuote(s:4) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:27:53,457 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:53,457 TRACE [JDBCQueryCommand] Setting parm[0] s:4
23:27:53,458 TRACE [JDBCQueryCommand] 1 were returned.
23:27:53,460 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:53,460 TRACE [JDBCQueryCommand] Setting parm[0] s:4
23:27:53,461 TRACE [JDBCQueryCommand] 1 were returned.
23:27:53,462 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:53,462 TRACE [JDBCQueryCommand] Setting parm[0] s:4
23:27:53,463 TRACE [JDBCQueryCommand] 1 were returned.
23:27:53,464 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:53,464 TRACE [JDBCQueryCommand] Setting parm[0] s:4
23:27:53,465 TRACE [JDBCQueryCommand] 1 were returned.
23:27:53,466 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:53,466 TRACE [JDBCQueryCommand] Setting parm[0] s:4
23:27:53,467 TRACE [JDBCQueryCommand] 1 were returned.
23:27:53,468 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:53,469 TRACE [JDBCQueryCommand] Setting parm[0] s:4
23:27:53,470 TRACE [JDBCQueryCommand] 1 were returned.
23:27:53,472 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:53,472 TRACE [JDBCQueryCommand] Setting parm[0] s:4
23:27:53,474 TRACE [JDBCQueryCommand] 1 were returned.
23:27:53,476 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
23:27:53,476 TRACE [JDBCQueryCommand] Setting parm[0] s:4
23:27:53,476 TRACE [JDBCQueryCommand] 1 were returned.
{color:red}Also note that the above queries are executing multiple queries for the same quote. I thought we addressed this but maybe there was a regression. I can fix this by creating a pre-fetch of all columns but I think that should be the default behaviour.{color}
{panel}
{panel:title=Now let's try to purchase a Quote| borderStyle=dashed| borderColor=#ccc| titleBGColor=#F7D6C1| bgColor=#FFFFCE}
23:28:16,587 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:28:16,601 TRACE [Log] TradeAction:getClosedOrders(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:28:16,601 TRACE [Log] TradeBean:getClosedOrders(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:28:19,267 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
23:28:19,267 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:28:19,269 TRACE [JDBCQueryCommand] 1 were returned.
23:28:19,272 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
23:28:19,272 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:28:19,273 TRACE [JDBCQueryCommand] 1 were returned.
23:28:19,277 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
23:28:19,277 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:28:19,279 TRACE [JDBCQueryCommand] 1 were returned.
23:28:19,280 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID FROM OrderEJB o, AccountEJB T0 WHERE T0.accountID = o.account_accountID AND (o.orderStatus = 'closed' AND T0.accountID = ?)"
23:28:19,280 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:28:19,282 TRACE [JDBCQueryCommand] 0 were returned.
23:28:19,290 DEBUG [Log] DayTrader Log:Mon Dec 11 23:28:19 EST 2006------
23:28:19,291 DEBUG [Log] OrderAlertFilter: userID=uid:0 closedOrders=
23:28:19,291 DEBUG [Log] DayTrader Log:Mon Dec 11 23:28:19 EST 2006------
23:28:19,291 DEBUG [Log] ---Log.printCollection -- collection size=0
23:28:19,291 DEBUG [Log] DayTrader Log:Mon Dec 11 23:28:19 EST 2006------
23:28:19,291 DEBUG [Log] ---Log.printCollection -- complete
23:28:19,291 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:28:19,305 TRACE [Log] TradeAction:buy(uid:0, s:0, 100.0), 0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:28:19,318 TRACE [Log] TradeBean:buy(uid:0, s:0, 100.0), 0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:28:20,512 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
23:28:20,513 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:28:20,516 TRACE [JDBCQueryCommand] 1 were returned.
23:28:20,518 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
23:28:20,518 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
23:28:20,519 TRACE [JDBCQueryCommand] 1 were returned.
23:28:22,801 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
23:28:22,801 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:28:22,802 TRACE [JDBCQueryCommand] 1 were returned.
23:28:22,804 TRACE [Log] KeySequenceBean:getNextID - return new PK ID for Entity type: order ID=1006 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:28:22,805 TRACE [Log] TradeBean:createOrder(orderID=1006 account=0 quote=s:0 orderType=buy quantity=100.0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
23:28:22,806 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
23:28:22,806 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:28:22,812 TRACE [JDBCQueryCommand] 1 were returned.
23:28:22,814 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.orderID FROM OrderEJB T WHERE T.account_accountID = ?"
23:28:22,814 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:28:22,815 TRACE [JDBCQueryCommand] 3 were returned.
23:28:22,817 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.orderID FROM OrderEJB T WHERE T.quote_symbol = ?"
23:28:22,817 TRACE [JDBCQueryCommand] Setting parm[0] s:0
23:28:22,828 TRACE [JDBCQueryCommand] 1 were returned.
23:28:22,831 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.balance FROM AccountEJB A WHERE A.accountID = ?"
23:28:22,831 TRACE [JDBCQueryCommand] Setting parm[0] 0
23:28:22,832 TRACE [JDBCQueryCommand] 1 were returned.
{color:red}This is odd...at this point we have already created the order but the INSERT statement was never executed. We take an exception and the application attempts to cancel the order (as there is a an Entity Object) but this SELECT fails because the INSERT was never executed.{color}
23:28:23,922 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID, o.completionDate, o.openDate, o.orderFee, o.orderStatus, o.orderType, o.price, o.quantity FROM OrderEJB o WHERE (o.orderID = ?)"
23:28:23,986 TRACE [JDBCQueryCommand] Setting parm[0] 1006
23:28:23,987 TRACE [JDBCQueryCommand] 0 were returned.
23:28:23,988 ERROR [Log] Error: TradeBean:buy(uid:0,s:0,100.0) --> failed
javax.ejb.ObjectNotFoundException
javax.ejb.ObjectNotFoundException
at org.apache.openejb.entity.cmp.TranqlSingleValuedQuery.execute(TranqlSingleValuedQuery.java:57)
at org.apache.openejb.entity.cmp.CmpFinder.execute(CmpFinder.java:42)
at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:396)
at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
at org.apache.openejb.entity.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:110)
at org.apache.openejb.entity.cmp.InTxCacheInterceptor.invoke(InTxCacheInterceptor.java:60)
at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:60)
at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer.invoke(DefaultCmpEjbContainer.java:150)
at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer$$FastClassByCGLIB$$e128ff0b.invoke(<generated>)
at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
at org.apache.openejb.BmpEjbContainer$$EnhancerByCGLIB$$371f743b.invoke(<generated>)
at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
at org.apache.openejb.proxy.EntityEJBLocalHome$$EnhancerByCGLIB$$434f6175.findByPrimaryKeyForUpdate(<generated>)
at org.apache.geronimo.samples.daytrader.ejb.TradeBean.completeOrderInternal(TradeBean.java:586)
at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:391)
at org.apache.geronimo.samples.daytrader.ejb.TradeBean$$FastClassByCGLIB$$7b99417a.invoke(<generated>)
at org.apache.openejb.dispatch.AbstractMethodOperation.invoke(AbstractMethodOperation.java:58)
at org.apache.openejb.slsb.BusinessMethod.execute(BusinessMethod.java:36)
at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
at org.apache.openejb.slsb.HandlerChainInterceptor.invoke(HandlerChainInterceptor.java:49)
at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:396)
at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
at org.apache.openejb.slsb.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:70)
at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:74)
at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Thread.java:613)
{color:red}Now some follow on statements are executed which will be rolled back because the whole tran is hosed at this point.{color}
23:28:24,015 TRACE [JDBCUpdateCommand] Prepared SQL Statement="UPDATE AccountEJB SET balance = ? WHERE accountID = ?"
23:28:24,016 TRACE [JDBCUpdateCommand] Setting parm[0]=0
23:28:24,016 TRACE [JDBCUpdateCommand] Setting parm[1]=965776.20
{color:red}And now the INSERT is being executed which will also get rolled back.{color}
23:28:24,022 TRACE [JDBCUpdateCommand] Prepared SQL Statement="INSERT INTO OrderEJB (completionDate, openDate, orderFee, orderID, orderStatus, orderType, price, quantity, account_accountID, quote_symbol, holding_holdingID) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)"
23:28:24,027 TRACE [JDBCUpdateCommand] Setting parm[0]=(null)
23:28:24,028 TRACE [JDBCUpdateCommand] Setting parm[1]=2006-12-11 23:28:22.806
23:28:24,029 TRACE [JDBCUpdateCommand] Setting parm[2]=24.95
23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[3]=1006
23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[4]=cancelled
23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[5]=buy
23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[6]=34.22
23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[7]=100.0
23:28:24,031 TRACE [JDBCUpdateCommand] Setting parm[8]=[Entity logical name=[AccountEJB]; physical name=[AccountEJB], 0]
23:28:24,031 TRACE [JDBCUpdateCommand] Setting parm[9]=[Entity logical name=[QuoteEJB]; physical name=[QuoteEJB], s:0]
23:28:24,031 TRACE [JDBCUpdateCommand] Setting parm[10]=(null)
23:28:24,034 WARN [Transaction] Error ending association for XAResource org.apache.geronimo.transaction.manager.WrapperNamedXAResource@6422c4; transaction will roll back. XA error code: 100
javax.transaction.xa.XAException
at org.apache.derby.jdbc.EmbedXAConnection.end(Unknown Source)
at org.apache.geronimo.transaction.manager.WrapperNamedXAResource.end(WrapperNamedXAResource.java:51)
at org.apache.geronimo.transaction.manager.TransactionImpl.endResources(TransactionImpl.java:571)
at org.apache.geronimo.transaction.manager.TransactionImpl.endResources(TransactionImpl.java:550)
at org.apache.geronimo.transaction.manager.TransactionImpl.rollback(TransactionImpl.java:472)
at org.apache.geronimo.transaction.manager.TransactionManagerImpl.rollback(TransactionManagerImpl.java:276)
at org.apache.geronimo.transaction.manager.TransactionManagerImpl$$FastClassByCGLIB$$14ee5fe0.invoke(<generated>)
at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
at org.apache.geronimo.transaction.manager.XidImporter$$EnhancerByCGLIB$$9dba231b.rollback(<generated>)
at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:89)
at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Thread.java:613)
23:28:24,045 WARN [TradeEJB] TradeEJB
javax.ejb.EJBException: javax.ejb.ObjectNotFoundException
at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:404)
at org.apache.geronimo.samples.daytrader.ejb.TradeBean$$FastClassByCGLIB$$7b99417a.invoke(<generated>)
at org.apache.openejb.dispatch.AbstractMethodOperation.invoke(AbstractMethodOperation.java:58)
at org.apache.openejb.slsb.BusinessMethod.execute(BusinessMethod.java:36)
at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
at org.apache.openejb.slsb.HandlerChainInterceptor.invoke(HandlerChainInterceptor.java:49)
at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:396)
at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
at org.apache.openejb.slsb.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:70)
at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:74)
at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Thread.java:613)
Caused by: javax.ejb.ObjectNotFoundException
at org.apache.openejb.entity.cmp.TranqlSingleValuedQuery.execute(TranqlSingleValuedQuery.java:57)
at org.apache.openejb.entity.cmp.CmpFinder.execute(CmpFinder.java:42)
at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:396)
at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
at org.apache.openejb.entity.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:110)
at org.apache.openejb.entity.cmp.InTxCacheInterceptor.invoke(InTxCacheInterceptor.java:60)
at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:60)
at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer.invoke(DefaultCmpEjbContainer.java:150)
at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer$$FastClassByCGLIB$$e128ff0b.invoke(<generated>)
at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
at org.apache.openejb.BmpEjbContainer$$EnhancerByCGLIB$$371f743b.invoke(<generated>)
at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
at org.apache.openejb.proxy.EntityEJBLocalHome$$EnhancerByCGLIB$$434f6175.findByPrimaryKeyForUpdate(<generated>)
at org.apache.geronimo.samples.daytrader.ejb.TradeBean.completeOrderInternal(TradeBean.java:586)
at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:391)
... 61 more
23:28:24,047 ERROR [[TradeAppServlet]] Servlet.service() for servlet TradeAppServlet threw exception
java.rmi.RemoteException: javax.ejb.ObjectNotFoundException; nested exception is:
javax.ejb.EJBException: javax.ejb.ObjectNotFoundException
at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:154)
at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
at java.lang.Thread.run(Thread.java:613)
Caused by: javax.ejb.EJBException: javax.ejb.ObjectNotFoundException
at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:404)
at org.apache.geronimo.samples.daytrader.ejb.TradeBean$$FastClassByCGLIB$$7b99417a.invoke(<generated>)
at org.apache.openejb.dispatch.AbstractMethodOperation.invoke(AbstractMethodOperation.java:58)
at org.apache.openejb.slsb.BusinessMethod.execute(BusinessMethod.java:36)
at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
at org.apache.openejb.slsb.HandlerChainInterceptor.invoke(HandlerChainInterceptor.java:49)
at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:396)
at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
at org.apache.openejb.slsb.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:70)
at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:74)
at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
... 28 more
Caused by: javax.ejb.ObjectNotFoundException
at org.apache.openejb.entity.cmp.TranqlSingleValuedQuery.execute(TranqlSingleValuedQuery.java:57)
at org.apache.openejb.entity.cmp.CmpFinder.execute(CmpFinder.java:42)
at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
at java.security.AccessController.doPrivileged(Native Method)
at javax.security.auth.Subject.doAs(Subject.java:396)
at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
at org.apache.openejb.entity.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:110)
at org.apache.openejb.entity.cmp.InTxCacheInterceptor.invoke(InTxCacheInterceptor.java:60)
at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:60)
at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer.invoke(DefaultCmpEjbContainer.java:150)
at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer$$FastClassByCGLIB$$e128ff0b.invoke(<generated>)
at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
at org.apache.openejb.BmpEjbContainer$$EnhancerByCGLIB$$371f743b.invoke(<generated>)
at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
at org.apache.openejb.proxy.EntityEJBLocalHome$$EnhancerByCGLIB$$434f6175.findByPrimaryKeyForUpdate(<generated>)
at org.apache.geronimo.samples.daytrader.ejb.TradeBean.completeOrderInternal(TradeBean.java:586)
at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:391)
... 61 more
{panel}
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Commented: (GERONIMO-2649) Insert of new EJB does not appear
to be occurring
Posted by "Matt Hogstrom (JIRA)" <ji...@apache.org>.
[ http://issues.apache.org/jira/browse/GERONIMO-2649?page=comments#action_12457727 ]
Matt Hogstrom commented on GERONIMO-2649:
-----------------------------------------
Thanks Gianny, I didn't see a commit to tranql so when you indicate that its been fixed I assume you'll be posting a patch to tranql/trunk.
As far as the input bindings I went back and looked and I see what you mean. Thanks for the clarification.
> Insert of new EJB does not appear to be occurring
> -------------------------------------------------
>
> Key: GERONIMO-2649
> URL: http://issues.apache.org/jira/browse/GERONIMO-2649
> Project: Geronimo
> Issue Type: Bug
> Security Level: public(Regular issues)
> Affects Versions: 1.2, 2.0-M1
> Environment: Mac OS X
> Reporter: Matt Hogstrom
> Assigned To: Matt Hogstrom
> Priority: Blocker
> Fix For: 1.2, 2.0-M1
>
>
> Buy of a stock is not working correctly. It appears that the database insert is not flushing at the right time and this is causing subsequent finders to fail. I have included some tracing here to hopefully isolate the problem. If you could take a look at this perhaps you can shed some light on the problem.
> This is against Geronimo 1.2 and the published TranQL 1.4-SNAPSHOT. Please do and svn up of TranQL and build locally. I'll release it tomorrow but my config is hosed tonight.
> I'm using daytrader-ear-2.0-SNAPSHOT and the daytrader-jpa-plan.xml located in http://svn.apache.org/repos/asf/geronimo/daytrader/trunk/plans/daytrader-jpa-plan.xml
> In the configuration panel choose the option to create the tables. Once this is done populate the tables.
> I snipped out the connection mgmt stuff so you'll simply see the JDBC operations.
> You can then re-create by following this sequence from the main DayTrader login:
> Login to uid:0 (all passwords are xxx)
> Select quote operation
> Buy a stock
> When purchasing a stock a new order is created. However, the actual row does not appear to be flushed to the database and subsequent finds fail. Here is the sequence of events.
> {panel:title=Login to uid:0| borderStyle=dashed| borderColor=#ccc| titleBGColor=#F7D6C1| bgColor=#FFFFCE}
> 23:27:20,576 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:27:20,577 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:20,578 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:20,580 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:27:20,581 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:20,581 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:20,583 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
> 23:27:20,585 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:20,586 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:20,588 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID FROM OrderEJB o, AccountEJB T0 WHERE T0.accountID = o.account_accountID AND (o.orderStatus = 'closed' AND T0.accountID = ?)"
> 23:27:20,588 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:20,592 TRACE [JDBCQueryCommand] 0 were returned.
> 23:27:20,600 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:20 EST 2006------
>
> 23:27:20,601 DEBUG [Log] OrderAlertFilter: userID=uid:0 closedOrders=
> 23:27:20,601 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:20 EST 2006------
>
> 23:27:20,601 DEBUG [Log] ---Log.printCollection -- collection size=0
> 23:27:20,601 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:20 EST 2006------
>
> 23:27:20,624 DEBUG [Log] ---Log.printCollection -- complete
> 23:27:20,624 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:20,627 TRACE [Log] TradeAction:login(uid:0, xxx) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:21,840 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:27:21,840 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:21,841 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:21,844 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:27:21,845 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:21,847 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:21,848 TRACE [Log] TradeBean:login(uid:0, xxx) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:21,849 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
> 23:27:21,849 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:21,850 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:21,851 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.profile_userID FROM AccountEJB T WHERE T.accountID = ?"
> 23:27:21,851 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:21,852 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:21,854 TRACE [Log] TradeBean:login(uid:0,xxx) success
> Account Data for account: 0
> loginCount:8
> logoutCount:0
> lastLogin:2006-12-11 23:27:21.854
> creationDate:2006-12-11 20:57:22.969
> balance:969223.15
> openBalance:1000000.00
> profileID:uid:0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> {color:red} The following interaction concerns me as the parm values and the parameter markers seem backwards: {color}
> 23:27:21,856 TRACE [JDBCUpdateCommand] Prepared SQL Statement="UPDATE AccountEJB SET lastLogin = ?, loginCount = ? WHERE accountID = ?"
> 23:27:21,856 TRACE [JDBCUpdateCommand] Setting parm[0]=0
> 23:27:21,856 TRACE [JDBCUpdateCommand] Setting parm[1]=969223.15
> 23:27:21,857 TRACE [JDBCUpdateCommand] Setting parm[2]=2006-12-11 20:57:22.969
> 23:27:21,909 TRACE [Log] TradeAction:getAccountData(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:21,911 TRACE [Log] TradeBean:getAccountData(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,080 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:27:23,080 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:23,082 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,083 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:27:23,083 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:23,087 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,089 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
> 23:27:23,089 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:23,091 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,095 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.profile_userID FROM AccountEJB T WHERE T.accountID = ?"
> 23:27:23,095 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:23,096 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,107 TRACE [Log] TradeAction:getHoldings(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,108 TRACE [Log] TradeBean:getHoldings(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,110 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT h.holdingID, h.purchaseDate, h.purchasePrice, h.quantity FROM HOLDINGEJB h, AccountEJB T0, AccountProfileEJB T1 WHERE T0.accountID = h.account_accountID AND T1.userID = T0.profile_userID AND (T1.userID = ?)"
> 23:27:23,110 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:23,159 TRACE [JDBCQueryCommand] 3 were returned.
> 23:27:23,161 TRACE [Log] Got holdings collection size=3 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,164 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.quote_symbol FROM HOLDINGEJB T WHERE T.holdingID = ?"
> 23:27:23,165 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:23,165 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,167 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.quote_symbol FROM HOLDINGEJB T WHERE T.holdingID = ?"
> 23:27:23,167 TRACE [JDBCQueryCommand] Setting parm[0] 1
> 23:27:23,168 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,170 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.quote_symbol FROM HOLDINGEJB T WHERE T.holdingID = ?"
> 23:27:23,170 TRACE [JDBCQueryCommand] Setting parm[0] 2
> 23:27:23,171 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,192 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,193 TRACE [Log] TradeAction:getMarketSummary() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,193 TRACE [Log] TradeBean:getMarketSummary -- getting market summary threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,194 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT q.symbol, q.change1, q.companyName, q.high, q.low, q.open1, q.price, q.volume FROM QuoteEJB q WHERE (q.symbol LIKE 's:1__') ORDER BY q.change1 DESC"
> 23:27:23,283 TRACE [JDBCQueryCommand] 100 were returned.
> {panel}
> {panel:title=Now Clicking on Get Quotes| borderStyle=dashed| borderColor=#ccc| titleBGColor=#F7D6C1| bgColor=#FFFFCE}
> 23:27:46,296 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:27:46,297 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:46,298 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:46,302 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:27:46,302 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:46,304 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:46,307 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
> 23:27:46,307 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:46,309 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:46,311 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID FROM OrderEJB o, AccountEJB T0 WHERE T0.accountID = o.account_accountID AND (o.orderStatus = 'closed' AND T0.accountID = ?)"
> 23:27:46,311 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:46,313 TRACE [JDBCQueryCommand] 0 were returned.
> 23:27:46,316 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:46 EST 2006------
>
> 23:27:46,317 DEBUG [Log] OrderAlertFilter: userID=uid:0 closedOrders=
> 23:27:46,317 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:46 EST 2006------
>
> 23:27:46,319 DEBUG [Log] ---Log.printCollection -- collection size=0
> 23:27:46,330 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:46 EST 2006------
>
> 23:27:46,330 DEBUG [Log] ---Log.printCollection -- complete
> 23:27:46,330 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:46,334 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:46,342 TRACE [Log] TradeAction:getQuote(s:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:46,342 TRACE [Log] TradeBean:getQuote(s:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:48,264 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,264 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,267 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,277 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,277 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,278 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,280 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,281 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,282 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,283 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,283 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,284 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,285 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,285 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,286 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,288 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,288 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,290 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,291 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,291 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,292 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,294 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,294 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,295 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,354 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:48,357 TRACE [Log] TradeAction:getQuote(s:1) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:48,357 TRACE [Log] TradeBean:getQuote(s:1) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:49,211 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,211 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,212 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,214 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,214 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,215 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,216 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,216 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,217 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,219 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,219 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,220 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,221 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,221 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,222 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,224 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,224 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,225 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,226 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,227 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,227 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,229 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,229 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,229 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,276 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:49,277 TRACE [Log] TradeAction:getQuote(s:2) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:49,277 TRACE [Log] TradeBean:getQuote(s:2) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:50,178 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,178 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,179 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,181 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,181 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,181 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,183 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,183 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,335 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,336 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,336 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,337 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,339 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,339 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,340 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,341 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,341 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,341 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,484 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,484 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,485 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,486 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,486 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,486 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,499 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:50,501 TRACE [Log] TradeAction:getQuote(s:3) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:50,501 TRACE [Log] TradeBean:getQuote(s:3) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:52,480 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,481 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,483 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,485 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,485 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,486 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,488 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,489 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,489 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,492 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,492 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,493 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,495 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,495 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,496 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,498 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,498 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,499 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,500 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,500 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,501 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,502 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,502 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,503 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,514 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:52,517 TRACE [Log] TradeAction:getQuote(s:4) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:52,518 TRACE [Log] TradeBean:getQuote(s:4) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:53,457 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,457 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,458 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,460 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,460 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,461 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,462 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,462 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,463 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,464 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,464 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,465 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,466 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,466 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,467 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,468 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,469 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,470 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,472 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,472 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,474 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,476 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,476 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,476 TRACE [JDBCQueryCommand] 1 were returned.
> {color:red}Also note that the above queries are executing multiple queries for the same quote. I thought we addressed this but maybe there was a regression. I can fix this by creating a pre-fetch of all columns but I think that should be the default behaviour.{color}
> {panel}
> {panel:title=Now let's try to purchase a Quote| borderStyle=dashed| borderColor=#ccc| titleBGColor=#F7D6C1| bgColor=#FFFFCE}
> 23:28:16,587 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:16,601 TRACE [Log] TradeAction:getClosedOrders(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:16,601 TRACE [Log] TradeBean:getClosedOrders(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:19,267 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:28:19,267 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:28:19,269 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:19,272 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:28:19,272 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:28:19,273 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:19,277 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
> 23:28:19,277 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:28:19,279 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:19,280 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID FROM OrderEJB o, AccountEJB T0 WHERE T0.accountID = o.account_accountID AND (o.orderStatus = 'closed' AND T0.accountID = ?)"
> 23:28:19,280 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:28:19,282 TRACE [JDBCQueryCommand] 0 were returned.
> 23:28:19,290 DEBUG [Log] DayTrader Log:Mon Dec 11 23:28:19 EST 2006------
> 23:28:19,291 DEBUG [Log] OrderAlertFilter: userID=uid:0 closedOrders=
> 23:28:19,291 DEBUG [Log] DayTrader Log:Mon Dec 11 23:28:19 EST 2006------
>
> 23:28:19,291 DEBUG [Log] ---Log.printCollection -- collection size=0
> 23:28:19,291 DEBUG [Log] DayTrader Log:Mon Dec 11 23:28:19 EST 2006------
>
> 23:28:19,291 DEBUG [Log] ---Log.printCollection -- complete
> 23:28:19,291 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:19,305 TRACE [Log] TradeAction:buy(uid:0, s:0, 100.0), 0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:19,318 TRACE [Log] TradeBean:buy(uid:0, s:0, 100.0), 0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:20,512 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:28:20,513 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:28:20,516 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:20,518 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:28:20,518 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:28:20,519 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:22,801 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:28:22,801 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:28:22,802 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:22,804 TRACE [Log] KeySequenceBean:getNextID - return new PK ID for Entity type: order ID=1006 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:22,805 TRACE [Log] TradeBean:createOrder(orderID=1006 account=0 quote=s:0 orderType=buy quantity=100.0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:22,806 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:28:22,806 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:28:22,812 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:22,814 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.orderID FROM OrderEJB T WHERE T.account_accountID = ?"
> 23:28:22,814 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:28:22,815 TRACE [JDBCQueryCommand] 3 were returned.
> 23:28:22,817 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.orderID FROM OrderEJB T WHERE T.quote_symbol = ?"
> 23:28:22,817 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:28:22,828 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:22,831 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.balance FROM AccountEJB A WHERE A.accountID = ?"
> 23:28:22,831 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:28:22,832 TRACE [JDBCQueryCommand] 1 were returned.
> {color:red}This is odd...at this point we have already created the order but the INSERT statement was never executed. We take an exception and the application attempts to cancel the order (as there is a an Entity Object) but this SELECT fails because the INSERT was never executed.{color}
> 23:28:23,922 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID, o.completionDate, o.openDate, o.orderFee, o.orderStatus, o.orderType, o.price, o.quantity FROM OrderEJB o WHERE (o.orderID = ?)"
> 23:28:23,986 TRACE [JDBCQueryCommand] Setting parm[0] 1006
> 23:28:23,987 TRACE [JDBCQueryCommand] 0 were returned.
> 23:28:23,988 ERROR [Log] Error: TradeBean:buy(uid:0,s:0,100.0) --> failed
> javax.ejb.ObjectNotFoundException
> javax.ejb.ObjectNotFoundException
> at org.apache.openejb.entity.cmp.TranqlSingleValuedQuery.execute(TranqlSingleValuedQuery.java:57)
> at org.apache.openejb.entity.cmp.CmpFinder.execute(CmpFinder.java:42)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.entity.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:110)
> at org.apache.openejb.entity.cmp.InTxCacheInterceptor.invoke(InTxCacheInterceptor.java:60)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:60)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer.invoke(DefaultCmpEjbContainer.java:150)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer$$FastClassByCGLIB$$e128ff0b.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.BmpEjbContainer$$EnhancerByCGLIB$$371f743b.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.EntityEJBLocalHome$$EnhancerByCGLIB$$434f6175.findByPrimaryKeyForUpdate(<generated>)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.completeOrderInternal(TradeBean.java:586)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:391)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean$$FastClassByCGLIB$$7b99417a.invoke(<generated>)
> at org.apache.openejb.dispatch.AbstractMethodOperation.invoke(AbstractMethodOperation.java:58)
> at org.apache.openejb.slsb.BusinessMethod.execute(BusinessMethod.java:36)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.slsb.HandlerChainInterceptor.invoke(HandlerChainInterceptor.java:49)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.slsb.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:70)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:74)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
> at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
> at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
> at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
> at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
> at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
> at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
> at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
> at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
> at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
> at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
> at java.lang.Thread.run(Thread.java:613)
> {color:red}Now some follow on statements are executed which will be rolled back because the whole tran is hosed at this point.{color}
> 23:28:24,015 TRACE [JDBCUpdateCommand] Prepared SQL Statement="UPDATE AccountEJB SET balance = ? WHERE accountID = ?"
> 23:28:24,016 TRACE [JDBCUpdateCommand] Setting parm[0]=0
> 23:28:24,016 TRACE [JDBCUpdateCommand] Setting parm[1]=965776.20
> {color:red}And now the INSERT is being executed which will also get rolled back.{color}
> 23:28:24,022 TRACE [JDBCUpdateCommand] Prepared SQL Statement="INSERT INTO OrderEJB (completionDate, openDate, orderFee, orderID, orderStatus, orderType, price, quantity, account_accountID, quote_symbol, holding_holdingID) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)"
> 23:28:24,027 TRACE [JDBCUpdateCommand] Setting parm[0]=(null)
> 23:28:24,028 TRACE [JDBCUpdateCommand] Setting parm[1]=2006-12-11 23:28:22.806
> 23:28:24,029 TRACE [JDBCUpdateCommand] Setting parm[2]=24.95
> 23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[3]=1006
> 23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[4]=cancelled
> 23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[5]=buy
> 23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[6]=34.22
> 23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[7]=100.0
> 23:28:24,031 TRACE [JDBCUpdateCommand] Setting parm[8]=[Entity logical name=[AccountEJB]; physical name=[AccountEJB], 0]
> 23:28:24,031 TRACE [JDBCUpdateCommand] Setting parm[9]=[Entity logical name=[QuoteEJB]; physical name=[QuoteEJB], s:0]
> 23:28:24,031 TRACE [JDBCUpdateCommand] Setting parm[10]=(null)
> 23:28:24,034 WARN [Transaction] Error ending association for XAResource org.apache.geronimo.transaction.manager.WrapperNamedXAResource@6422c4; transaction will roll back. XA error code: 100
> javax.transaction.xa.XAException
> at org.apache.derby.jdbc.EmbedXAConnection.end(Unknown Source)
> at org.apache.geronimo.transaction.manager.WrapperNamedXAResource.end(WrapperNamedXAResource.java:51)
> at org.apache.geronimo.transaction.manager.TransactionImpl.endResources(TransactionImpl.java:571)
> at org.apache.geronimo.transaction.manager.TransactionImpl.endResources(TransactionImpl.java:550)
> at org.apache.geronimo.transaction.manager.TransactionImpl.rollback(TransactionImpl.java:472)
> at org.apache.geronimo.transaction.manager.TransactionManagerImpl.rollback(TransactionManagerImpl.java:276)
> at org.apache.geronimo.transaction.manager.TransactionManagerImpl$$FastClassByCGLIB$$14ee5fe0.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.geronimo.transaction.manager.XidImporter$$EnhancerByCGLIB$$9dba231b.rollback(<generated>)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:89)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
> at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
> at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
> at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
> at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
> at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
> at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
> at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
> at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
> at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
> at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
> at java.lang.Thread.run(Thread.java:613)
> 23:28:24,045 WARN [TradeEJB] TradeEJB
> javax.ejb.EJBException: javax.ejb.ObjectNotFoundException
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:404)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean$$FastClassByCGLIB$$7b99417a.invoke(<generated>)
> at org.apache.openejb.dispatch.AbstractMethodOperation.invoke(AbstractMethodOperation.java:58)
> at org.apache.openejb.slsb.BusinessMethod.execute(BusinessMethod.java:36)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.slsb.HandlerChainInterceptor.invoke(HandlerChainInterceptor.java:49)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.slsb.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:70)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:74)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
> at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
> at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
> at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
> at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
> at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
> at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
> at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
> at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
> at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
> at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
> at java.lang.Thread.run(Thread.java:613)
> Caused by: javax.ejb.ObjectNotFoundException
> at org.apache.openejb.entity.cmp.TranqlSingleValuedQuery.execute(TranqlSingleValuedQuery.java:57)
> at org.apache.openejb.entity.cmp.CmpFinder.execute(CmpFinder.java:42)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.entity.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:110)
> at org.apache.openejb.entity.cmp.InTxCacheInterceptor.invoke(InTxCacheInterceptor.java:60)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:60)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer.invoke(DefaultCmpEjbContainer.java:150)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer$$FastClassByCGLIB$$e128ff0b.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.BmpEjbContainer$$EnhancerByCGLIB$$371f743b.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.EntityEJBLocalHome$$EnhancerByCGLIB$$434f6175.findByPrimaryKeyForUpdate(<generated>)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.completeOrderInternal(TradeBean.java:586)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:391)
> ... 61 more
> 23:28:24,047 ERROR [[TradeAppServlet]] Servlet.service() for servlet TradeAppServlet threw exception
> java.rmi.RemoteException: javax.ejb.ObjectNotFoundException; nested exception is:
> javax.ejb.EJBException: javax.ejb.ObjectNotFoundException
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:154)
> at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
> at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
> at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
> at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
> at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
> at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
> at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
> at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
> at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
> at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
> at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
> at java.lang.Thread.run(Thread.java:613)
> Caused by: javax.ejb.EJBException: javax.ejb.ObjectNotFoundException
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:404)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean$$FastClassByCGLIB$$7b99417a.invoke(<generated>)
> at org.apache.openejb.dispatch.AbstractMethodOperation.invoke(AbstractMethodOperation.java:58)
> at org.apache.openejb.slsb.BusinessMethod.execute(BusinessMethod.java:36)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.slsb.HandlerChainInterceptor.invoke(HandlerChainInterceptor.java:49)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.slsb.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:70)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:74)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> ... 28 more
> Caused by: javax.ejb.ObjectNotFoundException
> at org.apache.openejb.entity.cmp.TranqlSingleValuedQuery.execute(TranqlSingleValuedQuery.java:57)
> at org.apache.openejb.entity.cmp.CmpFinder.execute(CmpFinder.java:42)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.entity.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:110)
> at org.apache.openejb.entity.cmp.InTxCacheInterceptor.invoke(InTxCacheInterceptor.java:60)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:60)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer.invoke(DefaultCmpEjbContainer.java:150)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer$$FastClassByCGLIB$$e128ff0b.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.BmpEjbContainer$$EnhancerByCGLIB$$371f743b.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.EntityEJBLocalHome$$EnhancerByCGLIB$$434f6175.findByPrimaryKeyForUpdate(<generated>)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.completeOrderInternal(TradeBean.java:586)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:391)
> ... 61 more
> {panel}
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
[jira] Resolved: (GERONIMO-2649) Insert of new EJB does not appear
to be occurring
Posted by "Gianny Damour (JIRA)" <ji...@apache.org>.
[ http://issues.apache.org/jira/browse/GERONIMO-2649?page=all ]
Gianny Damour resolved GERONIMO-2649.
-------------------------------------
Resolution: Fixed
Assignee: Matt Hogstrom (was: Gianny Damour)
Hi Matt, the problem was that the transactional cache was not flushed prior to execute the Finder findByPrimaryKeyForUpdate. This is a regression and it has been fixed.
Regarding the weird output of the trace statements (values seemed to be in the wrong order), the reason is that InputBinding[] are not in the order that you would expect. An InputBinding knows which index it sets a value for. I think that to accurately trace bindings, the best approach is to generate a dynamic proxy for PreparedStatement, which traces and delegates to the actual PreparedStatement. However, as Dain is moving to OpenJPA, it seems that TranQL will be discontinued very soon, so...
I will have a look to the prefetch stuff tomorrow night.
> Insert of new EJB does not appear to be occurring
> -------------------------------------------------
>
> Key: GERONIMO-2649
> URL: http://issues.apache.org/jira/browse/GERONIMO-2649
> Project: Geronimo
> Issue Type: Bug
> Security Level: public(Regular issues)
> Affects Versions: 1.2, 2.0-M1
> Environment: Mac OS X
> Reporter: Matt Hogstrom
> Assigned To: Matt Hogstrom
> Priority: Blocker
> Fix For: 1.2, 2.0-M1
>
>
> Buy of a stock is not working correctly. It appears that the database insert is not flushing at the right time and this is causing subsequent finders to fail. I have included some tracing here to hopefully isolate the problem. If you could take a look at this perhaps you can shed some light on the problem.
> This is against Geronimo 1.2 and the published TranQL 1.4-SNAPSHOT. Please do and svn up of TranQL and build locally. I'll release it tomorrow but my config is hosed tonight.
> I'm using daytrader-ear-2.0-SNAPSHOT and the daytrader-jpa-plan.xml located in http://svn.apache.org/repos/asf/geronimo/daytrader/trunk/plans/daytrader-jpa-plan.xml
> In the configuration panel choose the option to create the tables. Once this is done populate the tables.
> I snipped out the connection mgmt stuff so you'll simply see the JDBC operations.
> You can then re-create by following this sequence from the main DayTrader login:
> Login to uid:0 (all passwords are xxx)
> Select quote operation
> Buy a stock
> When purchasing a stock a new order is created. However, the actual row does not appear to be flushed to the database and subsequent finds fail. Here is the sequence of events.
> {panel:title=Login to uid:0| borderStyle=dashed| borderColor=#ccc| titleBGColor=#F7D6C1| bgColor=#FFFFCE}
> 23:27:20,576 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:27:20,577 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:20,578 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:20,580 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:27:20,581 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:20,581 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:20,583 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
> 23:27:20,585 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:20,586 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:20,588 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID FROM OrderEJB o, AccountEJB T0 WHERE T0.accountID = o.account_accountID AND (o.orderStatus = 'closed' AND T0.accountID = ?)"
> 23:27:20,588 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:20,592 TRACE [JDBCQueryCommand] 0 were returned.
> 23:27:20,600 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:20 EST 2006------
>
> 23:27:20,601 DEBUG [Log] OrderAlertFilter: userID=uid:0 closedOrders=
> 23:27:20,601 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:20 EST 2006------
>
> 23:27:20,601 DEBUG [Log] ---Log.printCollection -- collection size=0
> 23:27:20,601 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:20 EST 2006------
>
> 23:27:20,624 DEBUG [Log] ---Log.printCollection -- complete
> 23:27:20,624 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:20,627 TRACE [Log] TradeAction:login(uid:0, xxx) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:21,840 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:27:21,840 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:21,841 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:21,844 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:27:21,845 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:21,847 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:21,848 TRACE [Log] TradeBean:login(uid:0, xxx) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:21,849 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
> 23:27:21,849 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:21,850 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:21,851 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.profile_userID FROM AccountEJB T WHERE T.accountID = ?"
> 23:27:21,851 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:21,852 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:21,854 TRACE [Log] TradeBean:login(uid:0,xxx) success
> Account Data for account: 0
> loginCount:8
> logoutCount:0
> lastLogin:2006-12-11 23:27:21.854
> creationDate:2006-12-11 20:57:22.969
> balance:969223.15
> openBalance:1000000.00
> profileID:uid:0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> {color:red} The following interaction concerns me as the parm values and the parameter markers seem backwards: {color}
> 23:27:21,856 TRACE [JDBCUpdateCommand] Prepared SQL Statement="UPDATE AccountEJB SET lastLogin = ?, loginCount = ? WHERE accountID = ?"
> 23:27:21,856 TRACE [JDBCUpdateCommand] Setting parm[0]=0
> 23:27:21,856 TRACE [JDBCUpdateCommand] Setting parm[1]=969223.15
> 23:27:21,857 TRACE [JDBCUpdateCommand] Setting parm[2]=2006-12-11 20:57:22.969
> 23:27:21,909 TRACE [Log] TradeAction:getAccountData(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:21,911 TRACE [Log] TradeBean:getAccountData(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,080 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:27:23,080 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:23,082 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,083 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:27:23,083 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:23,087 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,089 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
> 23:27:23,089 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:23,091 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,095 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.profile_userID FROM AccountEJB T WHERE T.accountID = ?"
> 23:27:23,095 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:23,096 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,107 TRACE [Log] TradeAction:getHoldings(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,108 TRACE [Log] TradeBean:getHoldings(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,110 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT h.holdingID, h.purchaseDate, h.purchasePrice, h.quantity FROM HOLDINGEJB h, AccountEJB T0, AccountProfileEJB T1 WHERE T0.accountID = h.account_accountID AND T1.userID = T0.profile_userID AND (T1.userID = ?)"
> 23:27:23,110 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:23,159 TRACE [JDBCQueryCommand] 3 were returned.
> 23:27:23,161 TRACE [Log] Got holdings collection size=3 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,164 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.quote_symbol FROM HOLDINGEJB T WHERE T.holdingID = ?"
> 23:27:23,165 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:23,165 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,167 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.quote_symbol FROM HOLDINGEJB T WHERE T.holdingID = ?"
> 23:27:23,167 TRACE [JDBCQueryCommand] Setting parm[0] 1
> 23:27:23,168 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,170 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.quote_symbol FROM HOLDINGEJB T WHERE T.holdingID = ?"
> 23:27:23,170 TRACE [JDBCQueryCommand] Setting parm[0] 2
> 23:27:23,171 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:23,192 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,193 TRACE [Log] TradeAction:getMarketSummary() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,193 TRACE [Log] TradeBean:getMarketSummary -- getting market summary threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:23,194 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT q.symbol, q.change1, q.companyName, q.high, q.low, q.open1, q.price, q.volume FROM QuoteEJB q WHERE (q.symbol LIKE 's:1__') ORDER BY q.change1 DESC"
> 23:27:23,283 TRACE [JDBCQueryCommand] 100 were returned.
> {panel}
> {panel:title=Now Clicking on Get Quotes| borderStyle=dashed| borderColor=#ccc| titleBGColor=#F7D6C1| bgColor=#FFFFCE}
> 23:27:46,296 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:27:46,297 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:46,298 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:46,302 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:27:46,302 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:27:46,304 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:46,307 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
> 23:27:46,307 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:46,309 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:46,311 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID FROM OrderEJB o, AccountEJB T0 WHERE T0.accountID = o.account_accountID AND (o.orderStatus = 'closed' AND T0.accountID = ?)"
> 23:27:46,311 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:27:46,313 TRACE [JDBCQueryCommand] 0 were returned.
> 23:27:46,316 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:46 EST 2006------
>
> 23:27:46,317 DEBUG [Log] OrderAlertFilter: userID=uid:0 closedOrders=
> 23:27:46,317 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:46 EST 2006------
>
> 23:27:46,319 DEBUG [Log] ---Log.printCollection -- collection size=0
> 23:27:46,330 DEBUG [Log] DayTrader Log:Mon Dec 11 23:27:46 EST 2006------
>
> 23:27:46,330 DEBUG [Log] ---Log.printCollection -- complete
> 23:27:46,330 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:46,334 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:46,342 TRACE [Log] TradeAction:getQuote(s:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:46,342 TRACE [Log] TradeBean:getQuote(s:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:48,264 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,264 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,267 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,277 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,277 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,278 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,280 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,281 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,282 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,283 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,283 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,284 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,285 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,285 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,286 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,288 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,288 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,290 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,291 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,291 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,292 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,294 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:48,294 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:27:48,295 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:48,354 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:48,357 TRACE [Log] TradeAction:getQuote(s:1) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:48,357 TRACE [Log] TradeBean:getQuote(s:1) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:49,211 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,211 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,212 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,214 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,214 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,215 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,216 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,216 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,217 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,219 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,219 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,220 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,221 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,221 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,222 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,224 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,224 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,225 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,226 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,227 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,227 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,229 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:49,229 TRACE [JDBCQueryCommand] Setting parm[0] s:1
> 23:27:49,229 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:49,276 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:49,277 TRACE [Log] TradeAction:getQuote(s:2) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:49,277 TRACE [Log] TradeBean:getQuote(s:2) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:50,178 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,178 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,179 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,181 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,181 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,181 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,183 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,183 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,335 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,336 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,336 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,337 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,339 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,339 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,340 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,341 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,341 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,341 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,484 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,484 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,485 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,486 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:50,486 TRACE [JDBCQueryCommand] Setting parm[0] s:2
> 23:27:50,486 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:50,499 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:50,501 TRACE [Log] TradeAction:getQuote(s:3) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:50,501 TRACE [Log] TradeBean:getQuote(s:3) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:52,480 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,481 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,483 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,485 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,485 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,486 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,488 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,489 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,489 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,492 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,492 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,493 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,495 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,495 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,496 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,498 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,498 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,499 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,500 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,500 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,501 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,502 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:52,502 TRACE [JDBCQueryCommand] Setting parm[0] s:3
> 23:27:52,503 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:52,514 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:52,517 TRACE [Log] TradeAction:getQuote(s:4) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:52,518 TRACE [Log] TradeBean:getQuote(s:4) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:27:53,457 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,457 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,458 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,460 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.companyName FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,460 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,461 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,462 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.volume FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,462 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,463 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,464 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,464 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,465 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,466 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.open1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,466 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,467 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,468 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.low FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,469 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,470 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,472 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.high FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,472 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,474 TRACE [JDBCQueryCommand] 1 were returned.
> 23:27:53,476 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.change1 FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:27:53,476 TRACE [JDBCQueryCommand] Setting parm[0] s:4
> 23:27:53,476 TRACE [JDBCQueryCommand] 1 were returned.
> {color:red}Also note that the above queries are executing multiple queries for the same quote. I thought we addressed this but maybe there was a regression. I can fix this by creating a pre-fetch of all columns but I think that should be the default behaviour.{color}
> {panel}
> {panel:title=Now let's try to purchase a Quote| borderStyle=dashed| borderColor=#ccc| titleBGColor=#F7D6C1| bgColor=#FFFFCE}
> 23:28:16,587 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:16,601 TRACE [Log] TradeAction:getClosedOrders(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:16,601 TRACE [Log] TradeBean:getClosedOrders(uid:0) threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:19,267 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:28:19,267 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:28:19,269 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:19,272 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:28:19,272 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:28:19,273 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:19,277 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.accountID, A.balance, A.creationDate, A.lastLogin, A.loginCount, A.logoutCount, A.openBalance FROM AccountEJB A WHERE A.accountID = ?"
> 23:28:19,277 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:28:19,279 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:19,280 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID FROM OrderEJB o, AccountEJB T0 WHERE T0.accountID = o.account_accountID AND (o.orderStatus = 'closed' AND T0.accountID = ?)"
> 23:28:19,280 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:28:19,282 TRACE [JDBCQueryCommand] 0 were returned.
> 23:28:19,290 DEBUG [Log] DayTrader Log:Mon Dec 11 23:28:19 EST 2006------
> 23:28:19,291 DEBUG [Log] OrderAlertFilter: userID=uid:0 closedOrders=
> 23:28:19,291 DEBUG [Log] DayTrader Log:Mon Dec 11 23:28:19 EST 2006------
>
> 23:28:19,291 DEBUG [Log] ---Log.printCollection -- collection size=0
> 23:28:19,291 DEBUG [Log] DayTrader Log:Mon Dec 11 23:28:19 EST 2006------
>
> 23:28:19,291 DEBUG [Log] ---Log.printCollection -- complete
> 23:28:19,291 TRACE [Log] TradeAction:TradeAction() threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:19,305 TRACE [Log] TradeAction:buy(uid:0, s:0, 100.0), 0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:19,318 TRACE [Log] TradeBean:buy(uid:0, s:0, 100.0), 0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:20,512 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT a.userID, a.address, a.creditCard, a.email, a.fullName, a.passwd FROM AccountProfileEJB a WHERE (a.userID = ?)"
> 23:28:20,513 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:28:20,516 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:20,518 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.accountID FROM AccountEJB T WHERE T.profile_userID = ?"
> 23:28:20,518 TRACE [JDBCQueryCommand] Setting parm[0] uid:0
> 23:28:20,519 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:22,801 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.symbol FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:28:22,801 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:28:22,802 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:22,804 TRACE [Log] KeySequenceBean:getNextID - return new PK ID for Entity type: order ID=1006 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:22,805 TRACE [Log] TradeBean:createOrder(orderID=1006 account=0 quote=s:0 orderType=buy quantity=100.0 threadID=Thread[http-0.0.0.0-8080-Processor25,5,main]
> 23:28:22,806 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT Q.price FROM QuoteEJB Q WHERE Q.symbol = ?"
> 23:28:22,806 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:28:22,812 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:22,814 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.orderID FROM OrderEJB T WHERE T.account_accountID = ?"
> 23:28:22,814 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:28:22,815 TRACE [JDBCQueryCommand] 3 were returned.
> 23:28:22,817 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT T.orderID FROM OrderEJB T WHERE T.quote_symbol = ?"
> 23:28:22,817 TRACE [JDBCQueryCommand] Setting parm[0] s:0
> 23:28:22,828 TRACE [JDBCQueryCommand] 1 were returned.
> 23:28:22,831 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT A.balance FROM AccountEJB A WHERE A.accountID = ?"
> 23:28:22,831 TRACE [JDBCQueryCommand] Setting parm[0] 0
> 23:28:22,832 TRACE [JDBCQueryCommand] 1 were returned.
> {color:red}This is odd...at this point we have already created the order but the INSERT statement was never executed. We take an exception and the application attempts to cancel the order (as there is a an Entity Object) but this SELECT fails because the INSERT was never executed.{color}
> 23:28:23,922 TRACE [JDBCQueryCommand] Prepared SQL Statement="SELECT o.orderID, o.completionDate, o.openDate, o.orderFee, o.orderStatus, o.orderType, o.price, o.quantity FROM OrderEJB o WHERE (o.orderID = ?)"
> 23:28:23,986 TRACE [JDBCQueryCommand] Setting parm[0] 1006
> 23:28:23,987 TRACE [JDBCQueryCommand] 0 were returned.
> 23:28:23,988 ERROR [Log] Error: TradeBean:buy(uid:0,s:0,100.0) --> failed
> javax.ejb.ObjectNotFoundException
> javax.ejb.ObjectNotFoundException
> at org.apache.openejb.entity.cmp.TranqlSingleValuedQuery.execute(TranqlSingleValuedQuery.java:57)
> at org.apache.openejb.entity.cmp.CmpFinder.execute(CmpFinder.java:42)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.entity.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:110)
> at org.apache.openejb.entity.cmp.InTxCacheInterceptor.invoke(InTxCacheInterceptor.java:60)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:60)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer.invoke(DefaultCmpEjbContainer.java:150)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer$$FastClassByCGLIB$$e128ff0b.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.BmpEjbContainer$$EnhancerByCGLIB$$371f743b.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.EntityEJBLocalHome$$EnhancerByCGLIB$$434f6175.findByPrimaryKeyForUpdate(<generated>)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.completeOrderInternal(TradeBean.java:586)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:391)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean$$FastClassByCGLIB$$7b99417a.invoke(<generated>)
> at org.apache.openejb.dispatch.AbstractMethodOperation.invoke(AbstractMethodOperation.java:58)
> at org.apache.openejb.slsb.BusinessMethod.execute(BusinessMethod.java:36)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.slsb.HandlerChainInterceptor.invoke(HandlerChainInterceptor.java:49)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.slsb.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:70)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:74)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
> at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
> at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
> at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
> at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
> at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
> at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
> at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
> at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
> at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
> at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
> at java.lang.Thread.run(Thread.java:613)
> {color:red}Now some follow on statements are executed which will be rolled back because the whole tran is hosed at this point.{color}
> 23:28:24,015 TRACE [JDBCUpdateCommand] Prepared SQL Statement="UPDATE AccountEJB SET balance = ? WHERE accountID = ?"
> 23:28:24,016 TRACE [JDBCUpdateCommand] Setting parm[0]=0
> 23:28:24,016 TRACE [JDBCUpdateCommand] Setting parm[1]=965776.20
> {color:red}And now the INSERT is being executed which will also get rolled back.{color}
> 23:28:24,022 TRACE [JDBCUpdateCommand] Prepared SQL Statement="INSERT INTO OrderEJB (completionDate, openDate, orderFee, orderID, orderStatus, orderType, price, quantity, account_accountID, quote_symbol, holding_holdingID) VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)"
> 23:28:24,027 TRACE [JDBCUpdateCommand] Setting parm[0]=(null)
> 23:28:24,028 TRACE [JDBCUpdateCommand] Setting parm[1]=2006-12-11 23:28:22.806
> 23:28:24,029 TRACE [JDBCUpdateCommand] Setting parm[2]=24.95
> 23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[3]=1006
> 23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[4]=cancelled
> 23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[5]=buy
> 23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[6]=34.22
> 23:28:24,030 TRACE [JDBCUpdateCommand] Setting parm[7]=100.0
> 23:28:24,031 TRACE [JDBCUpdateCommand] Setting parm[8]=[Entity logical name=[AccountEJB]; physical name=[AccountEJB], 0]
> 23:28:24,031 TRACE [JDBCUpdateCommand] Setting parm[9]=[Entity logical name=[QuoteEJB]; physical name=[QuoteEJB], s:0]
> 23:28:24,031 TRACE [JDBCUpdateCommand] Setting parm[10]=(null)
> 23:28:24,034 WARN [Transaction] Error ending association for XAResource org.apache.geronimo.transaction.manager.WrapperNamedXAResource@6422c4; transaction will roll back. XA error code: 100
> javax.transaction.xa.XAException
> at org.apache.derby.jdbc.EmbedXAConnection.end(Unknown Source)
> at org.apache.geronimo.transaction.manager.WrapperNamedXAResource.end(WrapperNamedXAResource.java:51)
> at org.apache.geronimo.transaction.manager.TransactionImpl.endResources(TransactionImpl.java:571)
> at org.apache.geronimo.transaction.manager.TransactionImpl.endResources(TransactionImpl.java:550)
> at org.apache.geronimo.transaction.manager.TransactionImpl.rollback(TransactionImpl.java:472)
> at org.apache.geronimo.transaction.manager.TransactionManagerImpl.rollback(TransactionManagerImpl.java:276)
> at org.apache.geronimo.transaction.manager.TransactionManagerImpl$$FastClassByCGLIB$$14ee5fe0.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.geronimo.transaction.manager.XidImporter$$EnhancerByCGLIB$$9dba231b.rollback(<generated>)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:89)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
> at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
> at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
> at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
> at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
> at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
> at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
> at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
> at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
> at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
> at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
> at java.lang.Thread.run(Thread.java:613)
> 23:28:24,045 WARN [TradeEJB] TradeEJB
> javax.ejb.EJBException: javax.ejb.ObjectNotFoundException
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:404)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean$$FastClassByCGLIB$$7b99417a.invoke(<generated>)
> at org.apache.openejb.dispatch.AbstractMethodOperation.invoke(AbstractMethodOperation.java:58)
> at org.apache.openejb.slsb.BusinessMethod.execute(BusinessMethod.java:36)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.slsb.HandlerChainInterceptor.invoke(HandlerChainInterceptor.java:49)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.slsb.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:70)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:74)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
> at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
> at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
> at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
> at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
> at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
> at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
> at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
> at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
> at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
> at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
> at java.lang.Thread.run(Thread.java:613)
> Caused by: javax.ejb.ObjectNotFoundException
> at org.apache.openejb.entity.cmp.TranqlSingleValuedQuery.execute(TranqlSingleValuedQuery.java:57)
> at org.apache.openejb.entity.cmp.CmpFinder.execute(CmpFinder.java:42)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.entity.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:110)
> at org.apache.openejb.entity.cmp.InTxCacheInterceptor.invoke(InTxCacheInterceptor.java:60)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:60)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer.invoke(DefaultCmpEjbContainer.java:150)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer$$FastClassByCGLIB$$e128ff0b.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.BmpEjbContainer$$EnhancerByCGLIB$$371f743b.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.EntityEJBLocalHome$$EnhancerByCGLIB$$434f6175.findByPrimaryKeyForUpdate(<generated>)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.completeOrderInternal(TradeBean.java:586)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:391)
> ... 61 more
> 23:28:24,047 ERROR [[TradeAppServlet]] Servlet.service() for servlet TradeAppServlet threw exception
> java.rmi.RemoteException: javax.ejb.ObjectNotFoundException; nested exception is:
> javax.ejb.EJBException: javax.ejb.ObjectNotFoundException
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:154)
> at org.apache.openejb.proxy.SessionEJBObject$$EnhancerByCGLIB$$c8a10f29.buy(<generated>)
> at org.apache.geronimo.samples.daytrader.TradeAction.buy(TradeAction.java:154)
> at org.apache.geronimo.samples.daytrader.web.TradeServletAction.doBuy(TradeServletAction.java:225)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.performTask(TradeAppServlet.java:159)
> at org.apache.geronimo.samples.daytrader.web.TradeAppServlet.doGet(TradeAppServlet.java:77)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:595)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:688)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.geronimo.samples.daytrader.web.OrdersAlertFilter.doFilter(OrdersAlertFilter.java:91)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:202)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
> at org.apache.geronimo.tomcat.valve.DefaultSubjectValve.invoke(DefaultSubjectValve.java:56)
> at org.apache.geronimo.tomcat.GeronimoStandardContext$SystemMethodValve.invoke(GeronimoStandardContext.java:326)
> at org.apache.geronimo.tomcat.valve.GeronimoBeforeAfterValve.invoke(GeronimoBeforeAfterValve.java:31)
> at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
> at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
> at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
> at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:541)
> at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
> at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
> at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:667)
> at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
> at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
> at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
> at java.lang.Thread.run(Thread.java:613)
> Caused by: javax.ejb.EJBException: javax.ejb.ObjectNotFoundException
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:404)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean$$FastClassByCGLIB$$7b99417a.invoke(<generated>)
> at org.apache.openejb.dispatch.AbstractMethodOperation.invoke(AbstractMethodOperation.java:58)
> at org.apache.openejb.slsb.BusinessMethod.execute(BusinessMethod.java:36)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.slsb.HandlerChainInterceptor.invoke(HandlerChainInterceptor.java:49)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.slsb.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:70)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:74)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.security.DefaultSubjectInterceptor.invoke(DefaultSubjectInterceptor.java:49)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer.invoke(DefaultStatelessEjbContainer.java:178)
> at org.apache.openejb.slsb.DefaultStatelessEjbContainer$$FastClassByCGLIB$$7ad7a562.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.StatelessEjbContainer$$EnhancerByCGLIB$$ea85b55.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> ... 28 more
> Caused by: javax.ejb.ObjectNotFoundException
> at org.apache.openejb.entity.cmp.TranqlSingleValuedQuery.execute(TranqlSingleValuedQuery.java:57)
> at org.apache.openejb.entity.cmp.CmpFinder.execute(CmpFinder.java:42)
> at org.apache.openejb.dispatch.DispatchInterceptor.invoke(DispatchInterceptor.java:34)
> at org.apache.openejb.security.EJBIdentityInterceptor$1.run(EJBIdentityInterceptor.java:49)
> at java.security.AccessController.doPrivileged(Native Method)
> at javax.security.auth.Subject.doAs(Subject.java:396)
> at org.apache.openejb.security.EJBIdentityInterceptor.invoke(EJBIdentityInterceptor.java:46)
> at org.apache.openejb.security.EjbSecurityInterceptor.invoke(EjbSecurityInterceptor.java:55)
> at org.apache.openejb.security.EjbRunAsInterceptor.invoke(EjbRunAsInterceptor.java:50)
> at org.apache.openejb.security.PolicyContextHandlerEJBInterceptor.invoke(PolicyContextHandlerEJBInterceptor.java:64)
> at org.apache.openejb.naming.ComponentContextInterceptor.invoke(ComponentContextInterceptor.java:51)
> at org.apache.openejb.ConnectionTrackingInterceptor.invoke(ConnectionTrackingInterceptor.java:56)
> at org.apache.openejb.entity.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:110)
> at org.apache.openejb.entity.cmp.InTxCacheInterceptor.invoke(InTxCacheInterceptor.java:60)
> at org.apache.openejb.transaction.TransactionContextInterceptor.invoke(TransactionContextInterceptor.java:50)
> at org.apache.openejb.transaction.TxRequired.invoke(TxRequired.java:60)
> at org.apache.openejb.transaction.TransactionPolicyInterceptor.invoke(TransactionPolicyInterceptor.java:50)
> at org.apache.openejb.NoConnectionEnlistingInterceptor.invoke(NoConnectionEnlistingInterceptor.java:68)
> at org.apache.openejb.SystemExceptionInterceptor.invoke(SystemExceptionInterceptor.java:35)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer.invoke(DefaultCmpEjbContainer.java:150)
> at org.apache.openejb.entity.cmp.DefaultCmpEjbContainer$$FastClassByCGLIB$$e128ff0b.invoke(<generated>)
> at net.sf.cglib.reflect.FastMethod.invoke(FastMethod.java:53)
> at org.apache.geronimo.gbean.runtime.FastMethodInvoker.invoke(FastMethodInvoker.java:38)
> at org.apache.geronimo.gbean.runtime.GBeanOperation.invoke(GBeanOperation.java:122)
> at org.apache.geronimo.gbean.runtime.GBeanInstance.invoke(GBeanInstance.java:820)
> at org.apache.geronimo.gbean.runtime.RawInvoker.invoke(RawInvoker.java:57)
> at org.apache.geronimo.kernel.basic.RawOperationInvoker.invoke(RawOperationInvoker.java:35)
> at org.apache.geronimo.kernel.basic.ProxyMethodInterceptor.intercept(ProxyMethodInterceptor.java:96)
> at org.apache.openejb.BmpEjbContainer$$EnhancerByCGLIB$$371f743b.invoke(<generated>)
> at org.apache.openejb.AbstractEjbDeployment.invoke(AbstractEjbDeployment.java:195)
> at org.apache.openejb.proxy.EJBMethodInterceptor.intercept(EJBMethodInterceptor.java:145)
> at org.apache.openejb.proxy.EntityEJBLocalHome$$EnhancerByCGLIB$$434f6175.findByPrimaryKeyForUpdate(<generated>)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.completeOrderInternal(TradeBean.java:586)
> at org.apache.geronimo.samples.daytrader.ejb.TradeBean.buy(TradeBean.java:391)
> ... 61 more
> {panel}
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators: http://issues.apache.org/jira/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira