Greetings,
We are utilizing a client/server (hub/spoke) topic implementation with
ActiveMQ-4.0-RC2 and have noticed a repeatable memory usage increase
reported by the UsageManager when a "SocketException: Broken pipe" error
occurs within the AbstractConnection.Transport. This has been repeatable
through forcing a client connection to ungracefully shutdown (eg, loosing
power).
What happens is that a memory usage spike occurs during the period of time
in which the broker has yet to learn that the client has disconnected (this
is expected). What is unexpected, is that the memory usage does not return
to the level it once was at before the client was ungracefully shutdown.
See the bottom of this posting for debug logging. The memory usage manager
has been reporting zero usage before any disconnection occurs; but after
each ungraceful disconnection you have an increased memory usage to the time
before. It does not take long for the usage manager to report 100 percent
and cause the publisher to stop dispatching messages after successive client
disconnects.
Note that we are utilizing useAsyncSend and dispatchAsync to help deal with
another issue of slow consumers. This was an issue that in the past caused
problems and appears to be addressed.
The issue that I am addressing here is that it is possible that power
failures on the client/subscriber can completely stop a publisher from
dispatching messages. Has this issue been seen by any others?
As an additional note with regards to statistics,
With a 10MB broker we have been receiving a 1-5% increase in memory usage
upon a single client experiencing an ungraceful shutdown. It also appears
that if multiple clients ungracefully shutdown around the same time this
problem is greatly exacerbated and a memory usage increase of 1-5% becomes a
memory usage increase of 20-30%.
Many thanks in advance,
Eric
Here is a greatly abbreviated snippet of the logs, as ActiveMQ is very
verbose at debug level logging.
<various messages are sent>
2007-02-16 12:11:50,541 DEBUG [org.apache.activemq.memory.UsageManager]
Memory usage change. from: 0, to: 1
<various messages are sent>
2007-02-16 12:12:04,536 DEBUG [org.apache.activemq.memory.UsageManager]
Memory usage change. from: 1, to: 2
<various messages are sent>
2007-02-16 12:12:17,530 DEBUG [org.apache.activemq.memory.UsageManager]
Memory usage change. from: 2, to: 3
<various messages are sent>
2007-02-16 12:12:30,736 DEBUG [org.apache.activemq.memory.UsageManager]
Memory usage change. from: 3, to: 4
<various messages are sent>
2007-02-16 12:12:39,860 DEBUG
[org.apache.activemq.broker.AbstractConnection.Transport] Transport failed:
java.net.SocketException: Broken pipe
java.net.SocketException: Broken pipe
at java.net.SocketOutputStream.socketWrite0(Native Method)
at java.net.SocketOutputStream.socketWrite(Unknown Source)
at java.net.SocketOutputStream.write(Unknown Source)
at
org.apache.activemq.transport.tcp.TcpBufferedOutputStream.flush(TcpBufferedOutputStream.java:108)
at java.io.DataOutputStream.flush(Unknown Source)
at
org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:121)
at
org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:141)
at
org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:86)
at
org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:77)
at
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:44)
at
org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:55)
at
org.apache.activemq.broker.TransportConnection.dispatch(TransportConnection.java:211)
at
org.apache.activemq.broker.AbstractConnection.processDispatch(AbstractConnection.java:568)
at
org.apache.activemq.broker.AbstractConnection.iterate(AbstractConnection.java:584)
at
org.apache.activemq.thread.SimpleTaskRunner.runTask(SimpleTaskRunner.java:110)
at
org.apache.activemq.thread.SimpleTaskRunner.access$100(SimpleTaskRunner.java:25)
at
org.apache.activemq.thread.SimpleTaskRunner$1.run(SimpleTaskRunner.java:43)
at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at
edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Unknown Source)
2007-02-16 12:12:39,874 DEBUG
[org.apache.activemq.broker.AbstractConnection.Transport] Transport failed:
java.net.SocketException: Connection reset
java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(Unknown Source)
at
org.apache.activemq.transport.tcp.TcpBufferedInputStream.fill(TcpBufferedInputStream.java:48)
at
org.apache.activemq.transport.tcp.TcpBufferedInputStream.read(TcpBufferedInputStream.java:55)
at java.io.DataInputStream.readInt(Unknown Source)
at
org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:270)
at
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:138)
at java.lang.Thread.run(Unknown Source)
2007-02-16 12:12:39,876 WARN
[org.apache.activemq.broker.jmx.ManagedTransportConnection] Failed to
unregister mbean:
org.apache.activemq:BrokerName=localhost,Type=Connection,Connection=ID_showstore-2-34723-1171656591200-2_0
2007-02-16 12:12:39,938 DEBUG [org.apache.activemq.memory.UsageManager]
Memory usage change. from: 4, to: 3
2007-02-16 12:12:39,940 DEBUG [org.apache.activemq.memory.UsageManager]
Memory usage change. from: 3, to: 2
2007-02-16 12:12:39,941 DEBUG [org.apache.activemq.memory.UsageManager]
Memory usage change. from: 2, to: 1
<<note that memory usage never goes back down to 0>>
--
View this message in context:
http://www.nabble.com/Memory-usage-increase-after-client-power-failure-tf3242706s2354.html#a9014365
Sent from the ActiveMQ - User mailing list archive at Nabble.com.
