Armin,

Good call.  I was pretty sure it wasn't a concurrency issue, but there's a 
long-forgotten daemon thread that's pre-loading all of the Counties after 
the servlet is initialized.  The failure occurs if this thread isn't done 
loading the Counties by the time the test starts running.  I'm not going 
to worry about it any more, since the chances of this happening in real 
life are essentially nil.

thanks,
-steve

Steve Clark
ECOS Development Group
[EMAIL PROTECTED]
(970)226-9291




Armin Waibel <[EMAIL PROTECTED]> 
05/19/2005 04:19 AM
Please respond to
"OJB Users List" <ojb-user@db.apache.org>


To
OJB Users List <ojb-user@db.apache.org>
cc

Subject
Re: Bug: Proxy materialization with ODMG






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]




---------------------------------------------------------------------
To unsubscribe, e-mail: [EMAIL PROTECTED]
For additional commands, e-mail: [EMAIL PROTECTED]

Reply via email to