activemq-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Jonas Lim (JIRA)" <j...@activemq.org>
Subject [jira] Resolved: (AMQ-557) durable mode: SQLException during broker shutdown, then IndexOutOfBoundsException in producer/consumer
Date Mon, 20 Mar 2006 11:42:26 GMT
     [ 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


Mime
View raw message