You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Jonas Lim (JIRA)" <ji...@activemq.org> on 2006/03/20 12:42:26 UTC
[jira] Resolved: (AMQ-557) durable mode: SQLException during broker
shutdown, then IndexOutOfBoundsException in producer/consumer
[ http://jira.activemq.org/jira//browse/AMQ-557?page=all ]
Jonas Lim resolved AMQ-557:
---------------------------
Resolution: Fixed
Was able to reproduce this issue on 4.0 M4 using oracle. Btw, it appears this issue only appears when using oracle (not really sure why). tried testing on mysql and mssql and didn't encounter the issue.
Tested it on the latest snapshot and issue appears to be resolved already
> durable mode: SQLException during broker shutdown, then IndexOutOfBoundsException in producer/consumer
> ------------------------------------------------------------------------------------------------------
>
> Key: AMQ-557
> URL: http://jira.activemq.org/jira//browse/AMQ-557
> Project: ActiveMQ
> Type: Bug
> Components: Broker
> Versions: 4.0 M4
> Reporter: Helmut Janknecht
> Assignee: Jonas Lim
>
>
> My use case:
> 1. Take the ActiveMQ 4.0-SNAPSHOT from yesterday (2006-02-12)
> 2. Change the conf/activemq.xml and configure an Oracle JDBC data source:
> <beans xmlns="http://activemq.org/config/1.0">
> <broker useJmx="true">
> <persistenceAdapter>
> <journaledJDBC journalLogFiles="5" dataDirectory="../activemq-data" dataSource="#oracle-ds"/>
> </persistenceAdapter>
>
> <transportConnectors>
> <transportConnector uri="tcp://localhost:61616"/>
> </transportConnectors>
> </broker>
>
> <bean id="oracle-ds" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
> <property name="driverClassName" value="oracle.jdbc.driver.OracleDriver"/>
> <property name="url" value="jdbc:oracle:thin:@acxlin:1521:acx"/>
> <property name="username" value="hase"/>
> <property name="password" value="hase"/>
> <property name="poolPreparedStatements" value="true"/>
> </bean>
> </beans>
> 3. Start the broker out of the box with bin/activemq
> 4. Change to the examples dir and change the build.xml and set
>
> <property name="durable" value="true" />
> 5. Invoke the producer with ant producer and then the consumer with ant consumer
> => Until here everything is fine, 10 messages are produced and consumed
> 6. No I wanted to test the durable mode and run the producer again with consuming the messages. So 10 mesages are left in the queue.
> 7. Shutdown the broker with bin/shutdown
> => First problem: java.sql.SQLException: Failed add a message
> INFO BrokerService - ActiveMQ JMS Message Broker (localhost) started
> INFO ManagementContext - JMX consoles can connect to service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi
> ...
> INFO BrokerService - ActiveMQ Message Broker (localhost) is shutting down
> INFO VMTransportFactory - Shutting down VM connectors for broker: localhost
> INFO TransactionContext - commit failed: Failed add a message
> java.sql.SQLException: Failed add a message
> at org.apache.activemq.store.jdbc.TransactionContext.executeBatch(TransactionContext.java:92)
> at org.apache.activemq.store.jdbc.TransactionContext.executeBatch(TransactionContext.java:68)
> at org.apache.activemq.store.jdbc.TransactionContext.commit(TransactionContext.java:146)
> at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.commitTransaction(JDBCPersistenceAdapter.java:313)
> at org.apache.activemq.store.journal.JournalPersistenceAdapter.commitTransaction(JournalPersistenceAdapter.java:177)
> at org.apache.activemq.store.journal.JournalMessageStore$3.execute(JournalMessageStore.java:269)
> at org.apache.activemq.util.TransactionTemplate.run(TransactionTemplate.java:43)
> at org.apache.activemq.store.journal.JournalMessageStore.checkpoint(JournalMessageStore.java:237)
> at org.apache.activemq.store.journal.JournalMessageStore.checkpoint(JournalMessageStore.java:211)
> at org.apache.activemq.store.journal.JournalPersistenceAdapter$4.call(JournalPersistenceAdapter.java:338)
> at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.run(FutureTask.java:166)
> at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:643)
> at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:668)
> at java.lang.Thread.run(Thread.java:595)
> ERROR JournalPersistenceAdapter - Failed to checkpoint a message store: edu.emory.mathcs.backport.java.util.concurrent.ExecutionException: java.io.IOException: Not started.
> edu.emory.mathcs.backport.java.util.concurrent.ExecutionException: java.io.IOException: Not started.
> at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.getResult(FutureTask.java:289)
> at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.get(FutureTask.java:115)
> at org.apache.activemq.store.journal.JournalPersistenceAdapter.doCheckpoint(JournalPersistenceAdapter.java:368)
> at org.apache.activemq.store.journal.JournalPersistenceAdapter$2.iterate(JournalPersistenceAdapter.java:120)
> 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:643)
> at edu.emory.mathcs.backport.java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:668)
> at java.lang.Thread.run(Thread.java:595)
> Caused by: java.io.IOException: Not started.
> at org.apache.activemq.store.jdbc.TransactionContext.rollback(TransactionContext.java:163)
> at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.rollbackTransaction(JDBCPersistenceAdapter.java:318)
> at org.apache.activemq.store.journal.JournalPersistenceAdapter.rollbackTransaction(JournalPersistenceAdapter.java:181)
> at org.apache.activemq.util.TransactionTemplate.run(TransactionTemplate.java:61)
> at org.apache.activemq.store.journal.JournalMessageStore.checkpoint(JournalMessageStore.java:237)
> at org.apache.activemq.store.journal.JournalMessageStore.checkpoint(JournalMessageStore.java:211)
> at org.apache.activemq.store.journal.JournalPersistenceAdapter$4.call(JournalPersistenceAdapter.java:338)
> at edu.emory.mathcs.backport.java.util.concurrent.FutureTask.run(FutureTask.java:166)
> ... 3 more
> INFO BrokerService - ActiveMQ JMS Message Broker (localhost) stopped: org.apache.activemq.broker.BrokerService$1@1ff92f5
> 8. Restart the broker
> => Some warnings occur:
> INFO BrokerService - ActiveMQ 4.0-SNAPSHOT JMS Message Broker (localhost) is starting
> INFO BrokerService - For help or more information please see: http://www.logicblaze.com
> INFO JDBCPersistenceAdapter - Database driver recognized: [oracle_jdbc_driver]
> INFO JournalPersistenceAdapter - Journal Recovery Started from: Active Journal: using 5 x 20.0 Megs at: ..\activemq-data\journal
> WARN JournalMessageStore - Could not replay add for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:1'. Message may have already been added. reason: java.io.IOException: Failed add a message
> WARN JournalMessageStore - Could not replay add for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:2'. Message may have already been added. reason: java.io.IOException: Failed add a message
> WARN JournalMessageStore - Could not replay add for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:3'. Message may have already been added. reason: java.io.IOException: Failed add a message
> WARN JournalMessageStore - Could not replay add for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:4'. Message may have already been added. reason: java.io.IOException: Failed add a message
> WARN JournalMessageStore - Could not replay add for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:5'. Message may have already been added. reason: java.io.IOException: Failed add a message
> WARN JournalMessageStore - Could not replay add for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:6'. Message may have already been added. reason: java.io.IOException: Failed add a message
> WARN JournalMessageStore - Could not replay add for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:7'. Message may have already been added. reason: java.io.IOException: Failed add a message
> WARN JournalMessageStore - Could not replay add for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:8'. Message may have already been added. reason: java.io.IOException: Failed add a message
> WARN JournalMessageStore - Could not replay add for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:9'. Message may have already been added. reason: java.io.IOException: Failed add a message
> WARN JournalMessageStore - Could not replay add for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:10'. Message may have already been added. reason: java.io.IOException: Failed add a message
> WARN JournalMessageStore - Could not replay acknowledge for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:1'. Message may have already been acknowledged. reason: java.io.IOException: Failed to remove a message
> WARN JournalMessageStore - Could not replay acknowledge for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:2'. Message may have already been acknowledged. reason: java.io.IOException: Failed to remove a message
> WARN JournalMessageStore - Could not replay acknowledge for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:3'. Message may have already been acknowledged. reason: java.io.IOException: Failed to remove a message
> WARN JournalMessageStore - Could not replay acknowledge for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:4'. Message may have already been acknowledged. reason: java.io.IOException: Failed to remove a message
> WARN JournalMessageStore - Could not replay acknowledge for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:5'. Message may have already been acknowledged. reason: java.io.IOException: Failed to remove a message
> WARN JournalMessageStore - Could not replay acknowledge for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:6'. Message may have already been acknowledged. reason: java.io.IOException: Failed to remove a message
> WARN JournalMessageStore - Could not replay acknowledge for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:7'. Message may have already been acknowledged. reason: java.io.IOException: Failed to remove a message
> WARN JournalMessageStore - Could not replay acknowledge for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:8'. Message may have already been acknowledged. reason: java.io.IOException: Failed to remove a message
> WARN JournalMessageStore - Could not replay acknowledge for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:9'. Message may have already been acknowledged. reason: java.io.IOException: Failed to remove a message
> WARN JournalMessageStore - Could not replay acknowledge for message 'ID:dopc-janknecht-3852-1139814332514-0:0:1:1:10'. Message may have already been acknowledged. reason: java.io.IOException: Failed to remove a message
> INFO JournalPersistenceAdapter - Journal Recovered: 30 message(s) in transactions recovered.
> INFO TransportServerThreadSupport - Listening for connections at: tcp://dopc-janknecht:61616
> INFO TransportConnector - Accepting connection on: tcp://dopc-janknecht:61616
> INFO BrokerService - ActiveMQ JMS Message Broker (localhost) started
> INFO ManagementContext - JMX consoles can connect to service:jmx:rmi:///jndi/rmi://localhost:1099/jmxrmi
> 9. Finally run the consumer
> => java.lang.IndexOutOfBoundsException
> consumer:
> [echo] Running consumer against server at $url = tcp://localhost:61616 for subject $subject = TEST.FOO
> [java] Connecting to URL: tcp://localhost:61616
> [java] Consuming queue: TEST.FOO
> [java] Using durable subscription
> [java] Exception in thread "tcp://localhost/127.0.0.1:61616" java.lang.IndexOutOfBoundsException
> [java] at java.io.DataInputStream.readFully(DataInputStream.java:173)
> [java] at org.apache.activemq.openwire.BooleanStream.unmarshal(BooleanStream.java:88)
> [java] at org.apache.activemq.openwire.OpenWireFormat.doUnmarshal(OpenWireFormat.java:213)
> [java] at org.apache.activemq.openwire.OpenWireFormat.unmarshal(OpenWireFormat.java:181)
> [java] at org.apache.activemq.transport.tcp.TcpTransport.run(TcpTransport.java:135)
> [java] at java.lang.Thread.run(Thread.java:595)
> The consumer hangs here..
> With durable=false everything is fine (except that I will loose my messages after a shutdown :-)
> Same behavior with the 4.0 M4.
> Sometime when repeating this test I don't get these "Could not replay add for message" warnings after
> broker restart but the consumer hangs everytime.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://jira.activemq.org/jira//secure/Administrators.jspa
-
For more information on JIRA, see:
http://www.atlassian.com/software/jira