You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@activemq.apache.org by "Tim Walters (JIRA)" <ji...@apache.org> on 2007/10/13 00:08:25 UTC

[jira] Commented: (AMQ-1063) Journaled JDBC checkpoint fails with java.io.IOException: Already started.

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

Tim Walters commented on AMQ-1063:
----------------------------------

I've been looking at the 4.1.1 code for checkpointing and think I've found a problem.

JDBC statements for copying messages to the longterm storage are handled by a TransactionContext object. If a SQLException is raised during execution of TransactionContext.commit(), the finally clause will close the JDBC connection and clear the 'inTx' flag showing a current transaction. However the exception will cause a TransactionContext.rollback() to be called, which will see the cleared 'inTx' flag and throw an exception with the 'Not started' message in the logs above. Also, the JDBC rollback() and statement close() methods won't be called correctly which could cause leaks or partial data commits.

JDBCPersistenceAdapter.log only logs SQL errors at the debug level, so the root cause of this problem is likely to be missing from the logs. My guess is that the different reports above might each reflect a different SQL error.

It looks like the minimal changes which should be made here are:

- Log SQL errors during commit() at a error level
- Make sure rollback() can be called after the commit() error.


> Journaled JDBC checkpoint fails with java.io.IOException: Already started.
> --------------------------------------------------------------------------
>
>                 Key: AMQ-1063
>                 URL: https://issues.apache.org/activemq/browse/AMQ-1063
>             Project: ActiveMQ
>          Issue Type: Bug
>          Components: Broker
>    Affects Versions: 5.0.0
>         Environment: Windows XP Professional, JVM 1.5.0_09, MySQL 5.0.27
>            Reporter: jk@penguinsfan.com
>            Assignee: Hiram Chirino
>             Fix For: 5.0.0
>
>
> I am running trunk using JDBC against MySQL 5.0.27.  I am seeing the above mentioned IOException.  Do not have specific instructions on how to reproduce at the current time, but I was using durable subscriptions with the store durable cursor if that helps.  (I'll post if I find out more information.)
>       <persistenceAdapter>
>    
>       <journaledJDBC journalLogFiles="5" dataDirectory="../activemq-data" dataSource="#mysql-ds"/>
>     </persistenceAdapter>
>   <bean id="mysql-ds" class="org.apache.commons.dbcp.BasicDataSource" destroy-method="close">
>     <property name="driverClassName" value="com.mysql.jdbc.Driver"/>
>     <property name="url" value="jdbc:mysql://localhost/activemq?relaxAutoCommit=true"/>
>     <property name="username" value="*** OMITTED ***"/>
>     <property name="password" value="*** OMITTED *** "/>
>     <property name="poolPreparedStatements" value="true"/>
>   </bean>  
> Log trace:
> 2006-11-19 19:19:48,078 [/127.0.0.1:4898] DEBUG JournalPersistenceAdapter      - Waking for checkpoint to complete.
> 2006-11-19 19:19:48,078 [eckpoint Worker] DEBUG JournalPersistenceAdapter      - Checkpoint started.
> 2006-11-19 19:19:48,078 [eckpoint Worker] ERROR JournalPersistenceAdapter      - Failed to checkpoint a message store: java.util.concurrent.ExecutionException: java.io.IOException: Already started.
> java.util.concurrent.ExecutionException: java.io.IOException: Already started.
> 	at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:205)
> 	at java.util.concurrent.FutureTask.get(FutureTask.java:80)
> 	at org.apache.activemq.store.journal.JournalPersistenceAdapter.doCheckpoint(JournalPersistenceAdapter.java:386)
> 	at org.apache.activemq.store.journal.JournalPersistenceAdapter$2.iterate(JournalPersistenceAdapter.java:129)
> 	at org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:88)
> 	at org.apache.activemq.thread.DedicatedTaskRunner.access$0(DedicatedTaskRunner.java:76)
> 	at org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:39)
> Caused by: java.io.IOException: Already started.
> 	at org.apache.activemq.store.jdbc.TransactionContext.begin(TransactionContext.java:145)
> 	at org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.beginTransaction(JDBCPersistenceAdapter.java:358)
> 	at org.apache.activemq.store.journal.JournalPersistenceAdapter.beginTransaction(JournalPersistenceAdapter.java:189)
> 	at org.apache.activemq.util.TransactionTemplate.run(TransactionTemplate.java:41)
> 	at org.apache.activemq.store.journal.JournalMessageStore.checkpoint(JournalMessageStore.java:247)
> 	at org.apache.activemq.store.journal.JournalTopicMessageStore.checkpoint(JournalTopicMessageStore.java:162)
> 	at org.apache.activemq.store.journal.JournalPersistenceAdapter$5.call(JournalPersistenceAdapter.java:373)
> 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:269)
> 	at java.util.concurrent.FutureTask.run(FutureTask.java:123)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
> 	at java.lang.Thread.run(Thread.java:595)
> 2006-11-19 19:19:48,109 [eckpoint Worker] DEBUG JournalPersistenceAdapter      - Checkpoint done.

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