You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@activemq.apache.org by Daniel Patterson <da...@danpat.net> on 2006/11/21 20:57:42 UTC

IO Errors from the journal?

Hey all,

  We're using ActiveMQ 4.0.2 on a Solaris 10 (sparc) machine to act as a 
re-broadcaster
  of messages from our production system (WebSphere MQ) for our developers.

  Every once in a while (like, twice a day), I'm seeing errors like the 
one below.

  Under some circumstances, this appears to cause ActiveMQ to stop 
recieving messages from
  the producers which are mirroring messages from WebSphereMQ.  At this 
point, we get backlogs
  of messages and nasty out-of-memory problems further upstream.

  The entire ActiveMQ process is running on an NFSv3 volume, so I'm not 
sure how derby likes
  playing with that.  We're process around 500k messages a day, between 
1kb and 20mb.

  Anyone seen this before?  I haven't yet tried turning of peristance, 
but I strongly suspect that it'll
  make this go away (at the expense of losing messages, which is 
something we don't want to do).

daniel

  2006-11-21 11:38:04,298 [eckpoint Worker] 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:299)
        at 
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.get(FutureTask.java:118)
        at 
org.apache.activemq.store.journal.JournalPersistenceAdapter.doCheckpoint(JournalPersistenceAdapter.java:380)
        at 
org.apache.activemq.store.journal.JournalPersistenceAdapter$2.iterate(JournalPersistenceAdapter.java:123)
        at 
org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:88)
        at 
org.apache.activemq.thread.DedicatedTaskRunner.access$000(DedicatedTaskRunner.java:25)
        at 
org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:39)
Caused by: java.io.IOException: Not started.
        at 
org.apache.activemq.store.jdbc.TransactionContext.rollback(TransactionContext.java:165)
        at 
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.rollbackTransaction(JDBCPersistenceAdapter.java:309)
        at 
org.apache.activemq.store.journal.JournalPersistenceAdapter.rollbackTransaction(JournalPersistenceAdapter.java:191)
        at 
org.apache.activemq.util.TransactionTemplate.run(TransactionTemplate.java:62)
        at 
org.apache.activemq.store.journal.JournalMessageStore.checkpoint(JournalMessageStore.java:247)
        at 
org.apache.activemq.store.journal.JournalTopicMessageStore.checkpoint(JournalTopicMessageStore.java:156)
        at 
org.apache.activemq.store.journal.JournalPersistenceAdapter$5.call(JournalPersistenceAdapter.java:367)
        at 
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.run(FutureTask.java:176)
        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(Thread.java:595)
2006-11-21 11:38:04,301 [eckpoint Worker] ERROR 
JournalPersistenceAdapter      - Failed to mark the Journal: 
org.apache.activeio.journal.InvalidRecordLocationException: The location 
is less than the last mark.
org.apache.activeio.journal.InvalidRecordLocationException: The location 
is less than the last mark.
        at 
org.apache.activeio.journal.active.JournalImpl.setMark(JournalImpl.java:340)
        at 
org.apache.activemq.store.journal.JournalPersistenceAdapter.doCheckpoint(JournalPersistenceAdapter.java:397)
        at 
org.apache.activemq.store.journal.JournalPersistenceAdapter$2.iterate(JournalPersistenceAdapter.java:123)
        at 
org.apache.activemq.thread.DedicatedTaskRunner.runTask(DedicatedTaskRunner.java:88)
        at 
org.apache.activemq.thread.DedicatedTaskRunner.access$000(DedicatedTaskRunner.java:25)
        at 
org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:39)

Re: IO Errors from the journal?

Posted by Hiram Chirino <hi...@hiramchirino.com>.
Looks like  derby error.  You might want to check with the derby folks
to see if they have any ideas what that error means.  Or you might try
running against a different kind of database to avoid the error.

On 11/22/06, Daniel Patterson <da...@danpat.net> wrote:
> Daniel Patterson wrote:
> >> I've turned off persistance "<broker persistance="false">" and that
> >> makes this problem go away, but
> >> the broker then uses large amounts of memory, seemingly uncapped.
> >> I've moved this process to
> >> a directory on local disk and re-enabled persistence, and the problem
> >> returns.
>
>   I've also turned on debug, and it reveals a little bit more
> information.  Just prior to the IOException: Not started
>   error, another exception is thrown by the JDBCPersistenceAdapter:
>
> 2006-11-22 08:37:24,880 [eckpoint worker] DEBUG
> JDBCPersistenceAdapter         - Commit failed: A truncation error was
> encountered trying to shrink BLOB 'XX-RESOLVE-XX' to length 1048576.,
> due to: A truncation error was encountered trying to shrink BLOB
> 'XX-RESOLVE-XX' to length 1048576.
> ERROR 22001: A truncation error was encountered trying to shrink BLOB
> 'XX-RESOLVE-XX' to length 1048576.
>         at
> org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
>         at
> org.apache.derby.iapi.types.SQLBinary.checkHostVariable(Unknown Source)
>         at
> org.apache.derby.exe.ac38c30028x010fx1048xc115xffff840419a80.e0(Unknown
> Source)
>         at
> org.apache.derby.impl.services.reflect.DirectCall.invoke(Unknown Source)
>         at
> org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(Unknown
> Source)
>         at
> org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(Unknown
> Source)
>         at
> org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(Unknown
> Source)
>         at
> org.apache.derby.impl.sql.execute.InsertResultSet.open(Unknown Source)
>         at
> org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
>         at
> org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
>         at
> org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeBatchElement(Unknown
> Source)
>         at
> org.apache.derby.impl.jdbc.EmbedStatement.executeBatch(Unknown Source)
>         at
> org.apache.activemq.store.jdbc.TransactionContext.executeBatch(TransactionContext.java:96)
>         at
> org.apache.activemq.store.jdbc.TransactionContext.executeBatch(TransactionContext.java:75)
>         at
> org.apache.activemq.store.jdbc.TransactionContext.commit(TransactionContext.java:154)
>         at
> org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.commitTransaction(JDBCPersistenceAdapter.java:363)
>         at
> org.apache.activemq.store.journal.JournalPersistenceAdapter.commitTransaction(JournalPersistenceAdapter.java:193)
>         at
> org.apache.activemq.store.journal.JournalMessageStore$3.execute(JournalMessageStore.java:271)
>         at
> org.apache.activemq.util.TransactionTemplate.run(TransactionTemplate.java:44)
>         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
> edu.emory.mathcs.backport.java.util.concurrent.FutureTask.run(FutureTask.java:176)
>         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(Thread.java:595)
> 2006-11-22 08:37:24,881 [eckpoint Worker] 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:299)
>         at
> edu.emory.mathcs.backport.java.util.concurrent.FutureTask.get(FutureTask.java:118)
>         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$000(DedicatedTaskRunner.java:25)
>         at
> org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:39)
> Caused by: java.io.IOException: Not started.
>         at
> org.apache.activemq.store.jdbc.TransactionContext.rollback(TransactionContext.java:168)
>         at
> org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.rollbackTransaction(JDBCPersistenceAdapter.java:368)
>         at
> org.apache.activemq.store.journal.JournalPersistenceAdapter.rollbackTransaction(JournalPersistenceAdapter.java:197)
>         at
> org.apache.activemq.util.TransactionTemplate.run(TransactionTemplate.java:62)
>         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
> edu.emory.mathcs.backport.java.util.concurrent.FutureTask.run(FutureTask.java:176)
>
>   Looks like a derby bug?  I don't have the flexibility ot setup any
> other JDBC store, what other options are there?
>
> daniel
>


-- 
Regards,
Hiram

Blog: http://hiramchirino.com

Re: IO Errors from the journal?

Posted by Vadim Pesochinsky <Va...@mscibarra.com>.
Hi Daniel!

Is there any resolution for this?

-- 
View this message in context: http://www.nabble.com/IO-Errors-from-the-journal--tf2681294.html#a8229683
Sent from the ActiveMQ - User mailing list archive at Nabble.com.

Re: IO Errors from the journal?

Posted by Daniel Patterson <da...@danpat.net>.
Daniel Patterson wrote:
>> I've turned off persistance "<broker persistance="false">" and that 
>> makes this problem go away, but
>> the broker then uses large amounts of memory, seemingly uncapped.  
>> I've moved this process to
>> a directory on local disk and re-enabled persistence, and the problem 
>> returns.

  I've also turned on debug, and it reveals a little bit more 
information.  Just prior to the IOException: Not started
  error, another exception is thrown by the JDBCPersistenceAdapter:

2006-11-22 08:37:24,880 [eckpoint worker] DEBUG 
JDBCPersistenceAdapter         - Commit failed: A truncation error was 
encountered trying to shrink BLOB 'XX-RESOLVE-XX' to length 1048576., 
due to: A truncation error was encountered trying to shrink BLOB 
'XX-RESOLVE-XX' to length 1048576.
ERROR 22001: A truncation error was encountered trying to shrink BLOB 
'XX-RESOLVE-XX' to length 1048576.
        at 
org.apache.derby.iapi.error.StandardException.newException(Unknown Source)
        at 
org.apache.derby.iapi.types.SQLBinary.checkHostVariable(Unknown Source)
        at 
org.apache.derby.exe.ac38c30028x010fx1048xc115xffff840419a80.e0(Unknown 
Source)
        at 
org.apache.derby.impl.services.reflect.DirectCall.invoke(Unknown Source)
        at 
org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(Unknown 
Source)
        at 
org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(Unknown 
Source)
        at 
org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(Unknown 
Source)
        at 
org.apache.derby.impl.sql.execute.InsertResultSet.open(Unknown Source)
        at 
org.apache.derby.impl.sql.GenericPreparedStatement.execute(Unknown Source)
        at 
org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(Unknown Source)
        at 
org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeBatchElement(Unknown 
Source)
        at 
org.apache.derby.impl.jdbc.EmbedStatement.executeBatch(Unknown Source)
        at 
org.apache.activemq.store.jdbc.TransactionContext.executeBatch(TransactionContext.java:96)
        at 
org.apache.activemq.store.jdbc.TransactionContext.executeBatch(TransactionContext.java:75)
        at 
org.apache.activemq.store.jdbc.TransactionContext.commit(TransactionContext.java:154)
        at 
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.commitTransaction(JDBCPersistenceAdapter.java:363)
        at 
org.apache.activemq.store.journal.JournalPersistenceAdapter.commitTransaction(JournalPersistenceAdapter.java:193)
        at 
org.apache.activemq.store.journal.JournalMessageStore$3.execute(JournalMessageStore.java:271)
        at 
org.apache.activemq.util.TransactionTemplate.run(TransactionTemplate.java:44)
        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 
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.run(FutureTask.java:176)
        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(Thread.java:595)
2006-11-22 08:37:24,881 [eckpoint Worker] 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:299)
        at 
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.get(FutureTask.java:118)
        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$000(DedicatedTaskRunner.java:25)
        at 
org.apache.activemq.thread.DedicatedTaskRunner$1.run(DedicatedTaskRunner.java:39)
Caused by: java.io.IOException: Not started.
        at 
org.apache.activemq.store.jdbc.TransactionContext.rollback(TransactionContext.java:168)
        at 
org.apache.activemq.store.jdbc.JDBCPersistenceAdapter.rollbackTransaction(JDBCPersistenceAdapter.java:368)
        at 
org.apache.activemq.store.journal.JournalPersistenceAdapter.rollbackTransaction(JournalPersistenceAdapter.java:197)
        at 
org.apache.activemq.util.TransactionTemplate.run(TransactionTemplate.java:62)
        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 
edu.emory.mathcs.backport.java.util.concurrent.FutureTask.run(FutureTask.java:176)

  Looks like a derby bug?  I don't have the flexibility ot setup any 
other JDBC store, what other options are there?

daniel

Re: IO Errors from the journal?

Posted by Daniel Patterson <da...@danpat.net>.
Daniel Patterson wrote:
> I've turned off persistance "<broker persistance="false">" and that 
> makes this problem go away, but
> the broker then uses large amounts of memory, seemingly uncapped.  
> I've moved this process to
> a directory on local disk and re-enabled persistence, and the problem 
> returns.
I've tried using the 4.1.0-RC2 release, the same symptoms occur.  I've 
also kept a JMX client attached and
watched the heap size over several hours.  The order of events goes 
something like this:

  1.  ActiveMQ startup, everything working fine.  I'm using mostly 
topics and I have 32 durable subscribers
       (all active for the duration of the test).
  2.  After a couple of hours of operation, and 20k messages, an 
"IOException: Not started" error is thrown
       by the journal code.
  3.  After this, memory usage slowly increases, in proportion to the 
number of messages recieved.  While we're
       below the maximum heap size, messages continue to flow.
  4.  We hit the maximum heap size.  There are no errors logged 
anywhere, but ActiveMQ stops responding
       and message flow halts.  Clients don't recieve any errors but 
simply block.  CPU usage is low, so
       it doesn't look like GC thrashing.

  I don't have a solid test-case to reproduce this, but should I go 
ahead and file a bug?

daniel

Re: IO Errors from the journal?

Posted by Daniel Patterson <da...@danpat.net>.
Daniel Patterson wrote:
> Hey all,
>
>  We're using ActiveMQ 4.0.2 on a Solaris 10 (sparc) machine to act as 
> a re-broadcaster
>  of messages from our production system (WebSphere MQ) for our 
> developers.
>
>  Every once in a while (like, twice a day), I'm seeing errors like the 
> one below.

I've turned off persistance "<broker persistance="false">" and that 
makes this problem go away, but
the broker then uses large amounts of memory, seemingly uncapped.  I've 
moved this process to
a directory on local disk and re-enabled persistence, and the problem 
returns.

daniel

Re: IO Errors from the journal?

Posted by "tom@hostwebase.com" <to...@hostwebase.com>.
Hi,

I have the same issue with large messages when trying to send large files. I
wonder whether you've had a solution ? Please share it with me.

I appreciate your help.


 
-- 
View this message in context: http://www.nabble.com/IO-Errors-from-the-journal--tf2681294s2354.html#a12275564
Sent from the ActiveMQ - User mailing list archive at Nabble.com.