Hi Steve,
could it be a concurrency problem? The odmg-tx is registered as a materialization listener for proxy objects. When the object will be materialized the listener is notified and TranactionImpl#afterMaterialization is called. This method checks if the tx is open, then the materialized object is registered.
org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
at java.lang.Thread.run(Thread.java:534)
Caused by: org.odmg.LockNotGrantedException: Locking failed for
gov.doi.tat.dataobjects.CountyDetailImpl{06055}, nested exception is:
[org.odmg.TransactionNotInProgressException: Transaction was not open,
call tx.begin() before perform action, current status is:
STATUS_NO_TRANSACTION]
at
org.apache.ojb.odmg.TransactionImpl.afterMaterialization(TransactionImpl.java:1050)Think the problem occur when a different thread try to materialize the proxy object while the odmg-tx is not completed, is in committing (on completion the odmg-tx remove itself as listener from the proxy object).
Did you share persistent object instances in different threads?
regards, Armin
[EMAIL PROTECTED] wrote:
I am encountering a bug which doesn't quite happen reliably, but happens about 75% of the time. The context is pretty large, so I'm going to just describe what's going on and see if anybody has any thoughts before I try to encapsulate it into a test case.
I'm using 1.0.3, ODMG, and the two-level cache. Most of my objects are proxied; I don't use collection proxies.
I have a Transaction inside which, among other things, I make calls which sometimes result in proxy materialization. The code looks something like this:
tx.begin();
if (! tx.isOpen()) LOGGER.error("*** Transaction is not open!!!");
Collection res = profile.getUtmZones();
if (res == null) {
res = new HashSet();
Iterator iter = profile.getCounties().iterator();
while (iter.hasNext()) {
CountyDetail cd = ((County) iter.next()).getDetail();
if (! tx.isOpen()) LOGGER.error("*** Mid-scan: Transaction is not open!!!");
res.addAll(cd.getUtmZones());
}
}
...
tx.commit();
In my test case, the getCounties() list has 40+ entries; each county has only a single UtmZone. Sometimes, the code runs to completion, and I end up with the correct contents in res. Other times, it throws the following Exception after processing a few (about a dozen) of the counties:
19:39:22,399 ERROR [] odmg.TransactionImpl (TransactionImpl.java:280) - Unexpected failure while locking
org.odmg.TransactionNotInProgressException: Transaction was not open, call tx.begin() before perform action, current status is: STATUS_NO_TRANSACTION
at org.apache.ojb.odmg.TransactionImpl.checkOpen(TransactionImpl.java:188)
at org.apache.ojb.odmg.TransactionImpl.getBroker(TransactionImpl.java:1115)
at org.apache.ojb.odmg.ObjectEnvelope.getBroker(ObjectEnvelope.java:116)
at org.apache.ojb.odmg.ObjectEnvelope.refreshObjectImage(ObjectEnvelope.java:174)
at org.apache.ojb.odmg.ObjectEnvelope.<init>(ObjectEnvelope.java:110)
at org.apache.ojb.odmg.ObjectEnvelopeTable.get(ObjectEnvelopeTable.java:420)
at org.apache.ojb.odmg.TransactionImpl.register(TransactionImpl.java:884)
at org.apache.ojb.odmg.TransactionImpl.lockAndRegister(TransactionImpl.java:267)
at org.apache.ojb.odmg.TransactionImpl.afterMaterialization(TransactionImpl.java:1045)
at org.apache.ojb.broker.core.proxy.IndirectionHandlerDefaultImpl.afterMaterialization(IndirectionHandlerDefaultImpl.java:176)
at org.apache.ojb.broker.core.proxy.IndirectionHandlerDefaultImpl.getRealSubject(IndirectionHandlerDefaultImpl.java:349)
at org.apache.ojb.broker.core.proxy.IndirectionHandlerDefaultImpl.invoke(IndirectionHandlerDefaultImpl.java:324)
at $Proxy4.getUtmZones(Unknown Source)
at gov.doi.tat.dao.odmg.OfficeProfileDaoImpl.getUtmZones(OfficeProfileDaoImpl.java:813)
This is all currently inside a WebApp, so it's a bit difficult to perfectly control the test environment. But my test methodology is to shut down Tomcat, start it up, and then go directly to the page which causes the error, so that it is the first page view in a fresh run. 'profile' is always the same object, and profile.getUtmZones() always returns null. This is the situation in which the code sometimes runs to completion and sometimes does not.
More info:
Profile.counties is a collection of proxied County's
County.detail is a proxied CountyDetail
County.utmZones is a collection of proxied UtmZone's
OfficeProfileDaoImpl.java:813 (the point at which the stack trace calls into OJB) is the res.addAll() line in the above code snippet
The "Mid-scan: Transaction is not open" message is not printed, so I assume that before I call getUtmZones(), I am in a valid Transaction
I have tried adding additional logging statements inside the loop. If they look at the proxied objects at all, the location of the error changes, but the same error occurs (i.e., some other proxied object fails to be locked because of STATUS_NO_TRANSACTION)
I have tried catching the PBException and examining the Transaction at that point. tx.isOpen() still returns true, and Implementation.currentTransaction() is still == tx
So I guess that it seems as if the proxy materialization is somehow calling back to some other Transaction that is no longer active. Anybody have any ideas on this?
thanks, -steve
Steve Clark ECOS Development Group [EMAIL PROTECTED] (970)226-9291
PS: For completeness, here's the entire stack trace once it gets wrapped as a PBException:
org.apache.ojb.broker.PersistenceBrokerException: Error invoking method getUtmZones
at org.apache.ojb.broker.core.proxy.IndirectionHandlerDefaultImpl.invoke(IndirectionHandlerDefaultImpl.java:334)
at $Proxy4.getUtmZones(Unknown Source)
at gov.doi.tat.dao.odmg.OfficeProfileDaoImpl.getUtmZones(OfficeProfileDaoImpl.java:817)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at gov.doi.tails.dao.odmg.TailsOfficeProfileDaoImpl.invokeMethod(TailsOfficeProfileDaoImpl.java:454)
at gov.doi.tat.dao.odmg.AbstractOdmgDaoImpl.doInTransaction(AbstractOdmgDaoImpl.java:103)
at gov.doi.tat.dao.odmg.OfficeProfileDaoImpl.getUtmZones(OfficeProfileDaoImpl.java:448)
at gov.doi.tails.biz.CustomizationMgr.getUtmZones(CustomizationMgr.java:608)
at gov.doi.tails.util.TailsApplicationContext$8.buildOptions(TailsApplicationContext.java:554)
at gov.doi.tails.util.LutOptionsCache.getOptions(LutOptionsCache.java:67)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:324)
at org.apache.commons.beanutils.PropertyUtils.getSimpleProperty(PropertyUtils.java:1185)
at org.apache.commons.beanutils.PropertyUtils.getNestedProperty(PropertyUtils.java:772)
at org.apache.commons.beanutils.PropertyUtils.getProperty(PropertyUtils.java:801)
at org.apache.struts.util.RequestUtils.lookup(RequestUtils.java:952)
at org.apache.struts.taglib.html.OptionsCollectionTag.doStartTag(OptionsCollectionTag.java:219)
at org.apache.jsp.codeData_jsp._jspService(codeData_jsp.java:900)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:137)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:210)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:295)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:241)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:684)
at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:575)
at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:498)
at org.apache.jasper.runtime.JspRuntimeLibrary.include(JspRuntimeLibrary.java:822)
at org.apache.jasper.runtime.PageContextImpl.include(PageContextImpl.java:398)
at org.apache.struts.tiles.TilesUtilImpl.doInclude(TilesUtilImpl.java:137)
at org.apache.struts.tiles.TilesUtil.doInclude(TilesUtil.java:177)
at org.apache.struts.taglib.tiles.InsertTag.doInclude(InsertTag.java:756)
at org.apache.struts.taglib.tiles.InsertTag$InsertHandler.doEndTag(InsertTag.java:881)
at org.apache.struts.taglib.tiles.InsertTag.doEndTag(InsertTag.java:473)
at org.apache.jsp.tabbedLayout_jsp._jspx_meth_tiles_insert_7(tabbedLayout_jsp.java:733)
at org.apache.jsp.tabbedLayout_jsp._jspService(tabbedLayout_jsp.java:269)
at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:137)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:210)
at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:295)
at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:241)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:684)
at org.apache.catalina.core.ApplicationDispatcher.doForward(ApplicationDispatcher.java:432)
at org.apache.catalina.core.ApplicationDispatcher.forward(ApplicationDispatcher.java:356)
at org.apache.struts.action.RequestProcessor.doForward(RequestProcessor.java:1069)
at org.apache.struts.tiles.TilesRequestProcessor.doForward(TilesRequestProcessor.java:274)
at org.apache.struts.tiles.TilesRequestProcessor.processTilesDefinition(TilesRequestProcessor.java:254)
at org.apache.struts.tiles.TilesRequestProcessor.processForwardConfig(TilesRequestProcessor.java:309)
at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:279)
at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
at org.apache.struts.action.ActionServlet.doPost(ActionServlet.java:525)
at gov.doi.tat.servlet.TatActionServlet.doPost(TatActionServlet.java:147)
at gov.doi.tails.util.TailsController.doGet(TailsController.java:89)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:740)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:247)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:193)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:256)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:492)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
at gov.doi.ecos.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:581)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
at org.apache.catalina.core.StandardContext.invoke(StandardContext.java:2422)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:180)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
at org.apache.catalina.valves.ErrorDispatcherValve.invoke(ErrorDispatcherValve.java:171)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:163)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:580)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
at org.apache.catalina.authenticator.EcosSingleSignOn.invoke(EcosSingleSignOn.java:159)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:174)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:643)
at org.apache.catalina.valves.RequestDumperValve.invoke(RequestDumperValve.java:221)
at org.apache.catalina.core.StandardPipeline$StandardPipelineValveContext.invokeNext(StandardPipeline.java:641)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:480)
at org.apache.catalina.core.ContainerBase.invoke(ContainerBase.java:995)
at org.apache.coyote.tomcat4.CoyoteAdapter.service(CoyoteAdapter.java:199)
at org.apache.jk.server.JkCoyoteHandler.invoke(JkCoyoteHandler.java:324)
at org.apache.jk.common.HandlerRequest.invoke(HandlerRequest.java:395)
at org.apache.jk.common.ChannelSocket.invoke(ChannelSocket.java:673)
at org.apache.jk.common.ChannelSocket.processConnection(ChannelSocket.java:615)
at org.apache.jk.common.SocketConnection.runIt(ChannelSocket.java:786)
at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:683)
at java.lang.Thread.run(Thread.java:534)
Caused by: org.odmg.LockNotGrantedException: Locking failed for gov.doi.tat.dataobjects.CountyDetailImpl{06055}, nested exception is: [org.odmg.TransactionNotInProgressException: Transaction was not open, call tx.begin() before perform action, current status is: STATUS_NO_TRANSACTION]
at org.apache.ojb.odmg.TransactionImpl.afterMaterialization(TransactionImpl.java:1050)
at org.apache.ojb.broker.core.proxy.IndirectionHandlerDefaultImpl.afterMaterialization(IndirectionHandlerDefaultImpl.java:176)
at org.apache.ojb.broker.core.proxy.IndirectionHandlerDefaultImpl.getRealSubject(IndirectionHandlerDefaultImpl.java:349)
at org.apache.ojb.broker.core.proxy.IndirectionHandlerDefaultImpl.invoke(IndirectionHandlerDefaultImpl.java:324)
... 101 more
--------------------------------------------------------------------- To unsubscribe, e-mail: [EMAIL PROTECTED] For additional commands, e-mail: [EMAIL PROTECTED]
--------------------------------------------------------------------- To unsubscribe, e-mail: [EMAIL PROTECTED] For additional commands, e-mail: [EMAIL PROTECTED]
