[prev in list] [next in list] [prev in thread] [next in thread] 

List:       activemq-dev
Subject:    [jira] [Created] (AMQ-4417) Unbalanced usage Exception in Valve.decrement
From:       "Vincent Baudry (JIRA)" <jira () apache ! org>
Date:       2013-03-29 9:35:15
Message-ID: JIRA.12639777.1364549639345.75332.1364549715818 () arcas
[Download RAW message or body]

Vincent Baudry created AMQ-4417:
-----------------------------------

             Summary: Unbalanced usage Exception in Valve.decrement
                 Key: AMQ-4417
                 URL: https://issues.apache.org/jira/browse/AMQ-4417
             Project: ActiveMQ
          Issue Type: Bug
    Affects Versions: 5.4.2
            Reporter: Vincent Baudry


One of our production node running ActiveMQ shows a permanent error log every \
milisecond :

Exception in thread "VMTransport" java.lang.IllegalStateException: Unbalanced usage: \
-274090111 at org.apache.activemq.thread.Valve.decrement(Valve.java:113) 
at org.apache.activemq.transport.vm.VMTransport.iterate(VMTransport.java:210) at \
org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:122)  at \
org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:43)  at \
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:678)  \
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:703)  \
at java.lang.Thread.run(Thread.java:811) 

The value behind unbalanced usage keeping moving but globally getting decremented \
over time.

We are for now unable to see the side effect on the app, which is still running, \
except the CPU usage going through the roof, probably because of this constant \
logging.

As the log doesn't have a root in our code, it's hard to understand what's gone wrong \
initially, and if it might be linked to our usage of ActiveMQ.

I've read the source code but can't understand why the valve usage int has gone \
initially negative. But it seems to me that when it has gone once negative, the only \
way to have the broker work fine again is to restart the server to reinitialize this \
value (as all subsequent iterate() / increment() calls will throw/catch an exception \
due to usage negative value and finally hit the decrement() method ).

As we don't have a scenario to reproduce the bug, I don't expect you to find a \
solution to it right now, but I wanted to file it in case anyone encounter the same \
bug and has the way to reproduce it.

And also I would be glad to have answers to the following questions, if possible :
- Do you have any clues concerning this issue ? Things I could investigate further ?
- Doest it seem normal to you that my exception log starts in a Thread.run() then \
                plugged to the PooledTaskRunner mechanism ?
- What kind of ActiveMQ tasks run using this PooledTaskRunner / VmTransport.iterate() \
                mechanism ? All AMQ tasks ? Only enqueueing/dequeueing tasks ? \
                Internal tasks ?
- Is it possible that some enqueueing/dequeueing tasks still work fine when in this \
state ? Is this faulty valve not shared by all producers connecting to the broker via \
vm:// ?

To give you a little technical context, we use this broker with a spring producer \
using Spring JmsTemplate through vm://transport

--
This message is automatically generated by JIRA.
If you think it was sent incorrectly, please contact your JIRA administrators
For more information on JIRA, see: http://www.atlassian.com/software/jira


[prev in list] [next in list] [prev in thread] [next in thread]