You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Albert Strasheim (JIRA)" <ji...@apache.org> on 2007/02/02 14:27:03 UTC

[jira] Commented: (AMQ-1148) Fast producer, slow consumer hangs after a few messages when using VMPendingSubscriberMessageStoragePolicy

    [ https://issues.apache.org/activemq/browse/AMQ-1148?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel#action_38461 ] 

Albert Strasheim commented on AMQ-1148:
---------------------------------------

It seems the ActiveMQ transport thread is getting stuck on UsageManager.waitForSpace:

Name: ActiveMQ Transport: tcp:///127.0.0.1:2694
State: WAITING on java.lang.Object@c98b07
Total blocked: 3  Total waited: 3

Stack trace: 
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:485)
org.apache.activemq.memory.UsageManager.waitForSpace(UsageManager.java:91)
org.apache.activemq.memory.UsageManager.waitForSpace(UsageManager.java:88)
org.apache.activemq.broker.region.Topic.send(Topic.java:248)
org.apache.activemq.broker.region.AbstractRegion.send(AbstractRegion.java:305)
org.apache.activemq.broker.region.RegionBroker.send(RegionBroker.java:381)
org.apache.activemq.broker.TransactionBroker.send(TransactionBroker.java:197)
org.apache.activemq.broker.BrokerFilter.send(BrokerFilter.java:126)
org.apache.activemq.broker.CompositeDestinationBroker.send(CompositeDestinationBroker.java:98)
org.apache.activemq.broker.MutableBrokerFilter.send(MutableBrokerFilter.java:136)
org.apache.activemq.broker.TransportConnection.processMessage(TransportConnection.java:449)
org.apache.activemq.command.ActiveMQMessage.visit(ActiveMQMessage.java:604)
org.apache.activemq.broker.TransportConnection.service(TransportConnection.java:258)
org.apache.activemq.broker.TransportConnection$1.onCommand(TransportConnection.java:164)
org.apache.activemq.transport.TransportFilter.onCommand(TransportFilter.java:65)
org.apache.activemq.transport.WireFormatNegotiator.onCommand(WireFormatNegotiator.java:133)
org.apache.activemq.transport.InactivityMonitor.onCommand(InactivityMonitor.java:122)
org.apache.activemq.transport.TransportSupport.doConsume(TransportSupport.java:84)
org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:137)
java.lang.Thread.run(Thread.java:619)

Meanwhile, all the ActiveMQ Session tasks are blocked:

Name: ActiveMQ Session Task
State: BLOCKED on java.lang.Object@94cbe2 owned by: Thread-3
Total blocked: 4  Total waited: 10

Stack trace: 
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:43)
org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1165)
org.apache.activemq.ActiveMQSession.asyncSendPacket(ActiveMQSession.java:1648)
org.apache.activemq.ActiveMQMessageConsumer.afterMessageIsConsumed(ActiveMQMessageConsumer.java:700)
org.apache.activemq.ActiveMQMessageConsumer.dispatch(ActiveMQMessageConsumer.java:871)
   - locked java.lang.Object@8978c7
org.apache.activemq.ActiveMQSessionExecutor.dispatch(ActiveMQSessionExecutor.java:99)
org.apache.activemq.ActiveMQSessionExecutor.iterate(ActiveMQSessionExecutor.java:166)
org.apache.activemq.thread.PooledTaskRunner.runTask(PooledTaskRunner.java:111)
org.apache.activemq.thread.PooledTaskRunner.access$1(PooledTaskRunner.java:95)
org.apache.activemq.thread.PooledTaskRunner$1.run(PooledTaskRunner.java:44)
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
java.lang.Thread.run(Thread.java:619)

Thread-3 seems to blocking on a write to the socket:

Name: Thread-3
State: RUNNABLE
Total blocked: 327  Total waited: 0

Stack trace: 
java.net.SocketOutputStream.socketWrite0(Native Method)
java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
java.net.SocketOutputStream.write(SocketOutputStream.java:136)
org.apache.activemq.transport.tcp.TcpBufferedOutputStream.flush(TcpBufferedOutputStream.java:109)
java.io.DataOutputStream.flush(DataOutputStream.java:106)
org.apache.activemq.transport.tcp.TcpTransport.oneway(TcpTransport.java:119)
org.apache.activemq.transport.InactivityMonitor.oneway(InactivityMonitor.java:141)
org.apache.activemq.transport.TransportFilter.oneway(TransportFilter.java:80)
org.apache.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:93)
org.apache.activemq.transport.MutexTransport.oneway(MutexTransport.java:44)
   - locked java.lang.Object@94cbe2
org.apache.activemq.transport.ResponseCorrelator.oneway(ResponseCorrelator.java:60)
org.apache.activemq.ActiveMQConnection.asyncSendPacket(ActiveMQConnection.java:1165)
org.apache.activemq.ActiveMQSession.send(ActiveMQSession.java:1546)
   - locked java.lang.Object@d4f13a
org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:473)
org.apache.activemq.ActiveMQMessageProducer.send(ActiveMQMessageProducer.java:358)
org.apache.activemq.broker.region.cursors.SlowConsumerTest$1.run(SlowConsumerTest.java:87)
java.lang.Thread.run(Thread.java:619)

> Fast producer, slow consumer hangs after a few messages when using VMPendingSubscriberMessageStoragePolicy
> ----------------------------------------------------------------------------------------------------------
>
>                 Key: AMQ-1148
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1148
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 4.2.0
>         Environment: Sun JDK 1.6.0 on Windows XP SP2 with VM arguments -Xms384m -Xmx512m
>            Reporter: Albert Strasheim
>            Priority: Critical
>             Fix For: 4.2.0
>
>         Attachments: SlowConsumerTest.java
>
>
> Following from this discussion:
> http://www.nabble.com/Fast-producer%2C-slow-consumer-with-spooling-to-disk--tf3123868.html
> Rob Davies implemented VMPendingSubscriberMessageStoragePolicy which, if I understand correctly, should cause a fast producer to block if a slow consumer can't keep up.
> However, when running the attached test case, the system seems to hang before the consumers have received much more than 5 messages. When it hangs probably depends on the heap size.
> I get this:
> 2007-02-02 13:44:23,281 [main           ] INFO  BrokerService                  - ActiveMQ null JMS Message Broker (localhost) is starting
> 2007-02-02 13:44:23,281 [main           ] INFO  BrokerService                  - For help or more information please see: http://incubator.apache.org/activemq/
> 2007-02-02 13:44:25,312 [main           ] INFO  JDBCPersistenceAdapter         - Database driver recognized: [apache_derby_embedded_jdbc_driver]
> 2007-02-02 13:44:26,500 [main           ] INFO  DefaultDatabaseLocker          - Attempting to acquire the exclusive lock to become the Master broker
> 2007-02-02 13:44:26,531 [main           ] INFO  DefaultDatabaseLocker          - Becoming the master on dataSource: org.apache.derby.jdbc.EmbeddedDataSource@1372656
> 2007-02-02 13:44:26,593 [main           ] INFO  JournalPersistenceAdapter      - Journal Recovery Started from: Active Journal: using 2 x 20.0 Megs at: C:\home\albert\work5\activemq\activemq-core\activemq-data\localhost\journal
> 2007-02-02 13:44:26,671 [main           ] INFO  JournalPersistenceAdapter      - Journal Recovered: 0 message(s) in transactions recovered.
> 2007-02-02 13:44:26,859 [main           ] INFO  BrokerService                  - Using Persistence Adapter: JournalPersistenceAdapator(JDBCPersistenceAdaptor(org.apache.derby.jdbc.EmbeddedDataSource@1372656))
> 2007-02-02 13:44:26,906 [main           ] INFO  JournalPersistenceAdapter      - Journal deleted: 
> 2007-02-02 13:44:29,296 [main           ] WARN  DefaultJDBCAdapter             - Could not create JDBC tables; they could already exist. Failure was: CREATE TABLE ACTIVEMQ_LOCK( ID BIGINT NOT NULL, TIME BIGINT, BROKER_NAME VARCHAR(250), PRIMARY KEY (ID) ) Message: Table/View 'ACTIVEMQ_LOCK' already exists in Schema 'APP'. SQLState: X0Y32 Vendor code: 30000
> 2007-02-02 13:44:29,343 [main           ] WARN  DefaultJDBCAdapter             - Could not create JDBC tables; they could already exist. Failure was: INSERT INTO ACTIVEMQ_LOCK(ID) VALUES (1) Message: The statement was aborted because it would have caused a duplicate key value in a unique or primary key constraint or unique index identified by 'SQL070130113001540' defined on 'ACTIVEMQ_LOCK'. SQLState: 23505 Vendor code: 30000
> 2007-02-02 13:44:29,484 [main           ] INFO  TransportServerThreadSupport   - Listening for connections at: tcp://ratbert:60706
> 2007-02-02 13:44:29,515 [main           ] INFO  TransportConnector             - Connector tcp://ratbert:60706 Started
> 2007-02-02 13:44:29,515 [main           ] INFO  BrokerService                  - ActiveMQ JMS Message Broker (localhost, ID:ratbert-2177-1170416663296-1:0) started
> 2007-02-02 13:44:29,578 [JMX connector  ] INFO  ManagementContext              - JMX consoles can connect to service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi
> 2007-02-02 13:44:29,625 [/127.0.0.1:2181] INFO  KahaStore                      - Kaha Store successfully deleted data directory activemq-data\localhost\tmp_storage
> GOT A MESSAGE BEING SLOW
> GOT A MESSAGE BEING SLOW
> GOT A MESSAGE BEING SLOW
> GOT A MESSAGE BEING SLOW
> GOT A MESSAGE BEING SLOW
> GOT A MESSAGE BEING SLOW
> GOT A MESSAGE BEING SLOW
> GOT A MESSAGE BEING SLOW
> GOT A MESSAGE BEING SLOW
> before it hangs.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.