at java.util.Observable.clearChanged(Observable.java) - waiting to lock <0x622d9aa8> (a org.ofbiz.entity.GenericValue)

[Rajendra Upa]

hi ,
I am getting very high CPU usage. I saw one of the Thread among other thread's as follow :

"http-0.0.0.0-8080-Processor6" daemon prio=1 tid=0x081e0430 nid=0x706a runnable [0x3c34f000..0x3c350030]
at java.util.Observable.clearChanged(Observable.java)
        - waiting to lock <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
        at java.util.Observable.notifyObservers(Observable.java:138)
        - locked <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
        at org.ofbiz.entity.GenericEntity.set(GenericEntity.java:402)
        - locked <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
        at org.ofbiz.entity.GenericEntity.setFields(GenericEntity.java:851)
        - locked <0x622d9aa8> (a org.ofbiz.entity.GenericValue)

From above thread dump , Processor6 is waiting for the lock on object which whose hashvalue is 0x622d9aa8 , but it has already got the lock for this object. I am not getting why this thread is waiting to acquire lock on object whom which it has already lock. Above code is executed in Multi environment , there could be many threads trying to acess the setFields() function of GenericEntity which is synchronized. setFields() function has set() method which again
snchronized and at the end it is notifying the observers. That point this thread is waiting for lock to invoke clearChange() which again synchronized.

It would be nice some one can provide some information that.

[David E Jones]

The best way to fix a dead lock of any sort is to, if possible, track  
down the code that caused it and see if changing that is possible.

In other words there is more to this stack trace and probably some  
related stack traces (that may not be logged or readily accessible  
because of the annoying nature of such problems) that refer to the  
code that is calling this code. Basically it is possible to write code  
to cause this behavior, both intentionally or through funny cross  
dependencies, so tracking down that code is the first step to fixing  
this and review of the code and what it does is the first step to  
deciding if that code needs to (or can) change, or if the  
synchronization needs to be relaxed on some of this stuff.

-David


On Apr 22, 2008, at 6:10 AM, Rajendra Upa wrote:

> - waiting to
> lock <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
> MIME-Version: 1.0
> Content-Type: text/plain; charset=us-ascii
> Content-Transfer-Encoding: 7bit
> X-Nabble-From: [hidden email]
>
>
> hi ,
> I am getting very high CPU usage. I saw one of the Thread among other
> thread's as follow :
>
> "http-0.0.0.0-8080-Processor6" daemon prio=1 tid=0x081e0430 nid=0x706a
> runnable [0x3c34f000..0x3c350030]
> at java.util.Observable.clearChanged(Observable.java)
> - waiting to lock <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
> at java.util.Observable.notifyObservers(Observable.java:138)
> - locked <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
> at org.ofbiz.entity.GenericEntity.set(GenericEntity.java:402)
> - locked <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
> at org.ofbiz.entity.GenericEntity.setFields(GenericEntity.java:851)
> - locked <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
>
> From above thread dump , Processor6 is waiting for the lock on  
> object which
> whose hashvalue is 0x622d9aa8 , but it has already got the lock for  
> this
> object. I am not getting why this thread is waiting to acquire lock on
> object whom which it has already lock. Above code is executed in Multi
> environment , there could be many threads trying to acess the  
> setFields()
> function of GenericEntity which is synchronized. setFields()  
> function has
> set() method which again
> snchronized and at the end it is notifying the observers. That point  
> this
> thread is waiting for lock to invoke clearChange() which again  
> synchronized.
>
> It would be nice some one can provide some information that.
> --
> View this message in context: http://www.nabble.com/at-java.util.Observable.clearChanged%28Observable.java%29%0D%0A--waiting-to-lock-%3C0x622d9aa8%3E-%28a-org.ofbiz.entity.GenericValue%29-tp16823826p16823826.html
> Sent from the OFBiz - User mailing list archive at Nabble.com.
>

[Rajendra Upa]

David E Jones wrote

The best way to fix a dead lock of any sort is to, if possible, track  
down the code that caused it and see if changing that is possible.

In other words there is more to this stack trace and probably some  
related stack traces (that may not be logged or readily accessible  
because of the annoying nature of such problems) that refer to the  
code that is calling this code. Basically it is possible to write code  
to cause this behavior, both intentionally or through funny cross  
dependencies, so tracking down that code is the first step to fixing  
this and review of the code and what it does is the first step to  
deciding if that code needs to (or can) change, or if the  
synchronization needs to be relaxed on some of this stuff.

-David


On Apr 22, 2008, at 6:10 AM, Rajendra Upa wrote:
> - waiting to
> lock <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
> MIME-Version: 1.0
> Content-Type: text/plain; charset=us-ascii
> Content-Transfer-Encoding: 7bit
> X-Nabble-From: [e-mail]
>
>
> hi ,
> I am getting very high CPU usage. I saw one of the Thread among other
> thread's as follow :
>
> "http-0.0.0.0-8080-Processor6" daemon prio=1 tid=0x081e0430 nid=0x706a
> runnable [0x3c34f000..0x3c350030]
> at java.util.Observable.clearChanged(Observable.java)
> - waiting to lock <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
> at java.util.Observable.notifyObservers(Observable.java:138)
> - locked <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
> at org.ofbiz.entity.GenericEntity.set(GenericEntity.java:402)
> - locked <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
> at org.ofbiz.entity.GenericEntity.setFields(GenericEntity.java:851)
> - locked <0x622d9aa8> (a org.ofbiz.entity.GenericValue)
>
> From above thread dump , Processor6 is waiting for the lock on  
> object which
> whose hashvalue is 0x622d9aa8 , but it has already got the lock for  
> this
> object. I am not getting why this thread is waiting to acquire lock on
> object whom which it has already lock. Above code is executed in Multi
> environment , there could be many threads trying to acess the  
> setFields()
> function of GenericEntity which is synchronized. setFields()  
> function has
> set() method which again
> snchronized and at the end it is notifying the observers. That point  
> this
> thread is waiting for lock to invoke clearChange() which again  
> synchronized.
>
> It would be nice some one can provide some information that.
> --
> View this message in context: http://www.nabble.com/at-java.util.Observable.clearChanged%28Observable.java%29%0D%0A--waiting-to-lock-%3C0x622d9aa8%3E-%28a-org.ofbiz.entity.GenericValue%29-tp16823826p16823826.html
> Sent from the OFBiz - User mailing list archive at Nabble.com.
>

Thanks for the quick reply. The code at which we are getting problem is in Ofbiz i.e GenericEntity.java . I think we should not doing any changes in GenericEntity as it owned by Ofbiz. We are just invoking setField() method of GenericEntity object from our code. And GenericEntity.setField() is synchronized method itself , ideally chances of concurrent use of the method would be zero. setField() method is calling another synchronized method set() and in the end set() method notifies the observers by invoking this.notifyObservers() which inturn internally invokes another synchronized method clearChange(). If you see above stack trace , One thread is waiting for a lock which it already had. We have added in plugin in eclipse which informs us that there were no Deadlocks but tool has notified about 'Orphan lock' . Info on 'Orphan lock' is available on Intenet.
Please provide us some information. Above problem causes very high CPU usage.

Does any one has similar problem before if yes Ofbiz has fixed that problem or it is not related to Ofbiz .

We have updated the our  ofbiz version from last two years.

For more more information , following is the thread dump
"http-0.0.0.0-8080-Processor6" daemon prio=1 tid=0x081e0430 nid=0x706a runnable [0x3c34f000..0x3c350030]
        at java.util.Observable.setChanged(Observable.java)
        - waiting to lock <0x622960d8> (a org.ofbiz.entity.GenericValue)
        at org.ofbiz.entity.GenericEntity.set(GenericEntity.java:401)
        - locked <0x622960d8> (a org.ofbiz.entity.GenericValue)
        at org.ofbiz.entity.GenericEntity.setFields(GenericEntity.java:851)
        - locked <0x622960d8> (a org.ofbiz.entity.GenericValue)
        at com.in2m.mvelopes.delegators.MvelopesDelegator.storeTransaction(MvelopesDelegator.java:613)
        at com.in2m.mvelopes.transaction.Transaction.store(Transaction.java:1190)
        at com.in2m.mvelopes.transaction.Transaction.updateModifiedTransactions(Transaction.java:1308)
        at com.in2m.mvelopes.isomorphic.commands.GetModifiedObjectsCommand.buildTransSyncPacket(GetModifiedObjectsCommand.java:900)
        at com.in2m.mvelopes.isomorphic.commands.GetModifiedObjectsCommand.buildSyncPackets(GetModifiedObjectsCommand.java:676)
        at com.in2m.mvelopes.flex.delegators.MvelopeDelegator.assignTransactionToMvelope(MvelopeDelegator.java:680)
        at sun.reflect.GeneratedMethodAccessor289.invoke(Unknown Source)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:585)
        at flashgateway.adapter.java.JavaAdapter.invokeFunction(JavaAdapter.java:55)
        at flashgateway.filter.AdapterFilter.invoke(AdapterFilter.java:117)
        at flashgateway.filter.MessageSecurityFilter.invoke(MessageSecurityFilter.java:144)
        at flashgateway.filter.ServiceNameFilter.invoke(ServiceNameFilter.java:101)
        at flashgateway.filter.EnvelopeFilter.invoke(EnvelopeFilter.java:102)
        at flashgateway.filter.SessionFilter.invoke(SessionFilter.java:28)
        at flashgateway.filter.LicenseFilter.invoke(LicenseFilter.java:57)
        at flashgateway.filter.ErrorFilter.invoke(ErrorFilter.java:39)
        at flashgateway.filter.LogFilter.invoke(LogFilter.java:46)
        at flashgateway.filter.BatchProcessFilter.invoke(BatchProcessFilter.java:63)
        at flashgateway.filter.PacketSecurityFilter.invoke(PacketSecurityFilter.java:68)
        at flashgateway.filter.DebugFilter.invoke(DebugFilter.java:38)
        at flashgateway.filter.SerializationFilter.invoke(SerializationFilter.java:89)
        at flashgateway.Gateway.invoke(Gateway.java:217)
        at flashgateway.controller.GatewayServlet.service(GatewayServlet.java:69)
        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.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
        at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
        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:664)
        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:595)