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]
