qpid-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Gordon Sim <g...@redhat.com>
Subject Re: Journal Full Error
Date Fri, 24 Jul 2009 18:18:47 GMT
Sandy Pratt wrote:
> I'm experimenting with the qpidd broker supplied with Fedora 10 (qpidd (qpidc) version
0.5 - the install should be up to date as of yesterday).
> Basically, I'm having a problem where I've been able to enqueue enough messages that
my journal is full and I can't start the broker because of this.  This is contrary to my understanding
of how persistent queues were supposed to work, in a number of ways:
> 
> 1) I thought producers were not allowed to commit messages past the 80% full point.

That was be understanding also. Kim any thoughts on how the journal 
could allow itself to get into a state where it can't be recovered?

> 2) I thought the flow-to-disk policy would result in excess messages being accepted into
a slower interim storage, not being rejected or causing the broker to crash.

Transient messages are stored in a different storage if they exceed the 
defined queue policy limit, and that grows as needed. Persistent 
messages however are written to the journal regardless of whether the 
queue policy limit which currently has a fixed size that must be defined 
up front.

> 
> 3) It appears as though I was able to crash the broker and cause the apparent loss of
acked messages simply by sending the broker too many?

Could you give a bit more detail on this point?

> 
> ...
> 
> Here are some details about what I was doing:
> 
> I created a queue with the following command:
> 
> qpid-config --durable add queue test3 --durable --limit-policy flow-to-disk
> 
> This created the following journal files:
> 
> [root@prattrs-fedora test3]# ll
> total 12356
> -rw-r----- 1 qpidd qpidd 1573376 2009-07-23 17:26 JournalData.0000.jdat
> -rw-r----- 1 qpidd qpidd 1573376 2009-07-23 17:27 JournalData.0001.jdat
> -rw-r----- 1 qpidd qpidd 1573376 2009-07-23 17:28 JournalData.0002.jdat
> -rw-r----- 1 qpidd qpidd 1573376 2009-07-23 17:28 JournalData.0003.jdat
> -rw-r----- 1 qpidd qpidd 1573376 2009-07-23 17:28 JournalData.0004.jdat
> -rw-r----- 1 qpidd qpidd 1573376 2009-07-23 17:29 JournalData.0005.jdat
> -rw-r----- 1 qpidd qpidd 1573376 2009-07-23 17:22 JournalData.0006.jdat
> -rw-r----- 1 qpidd qpidd 1573376 2009-07-23 17:22 JournalData.0007.jdat
> -rw-r----- 1 qpidd qpidd     866 2009-07-22 14:23 JournalData.jinf
> [root@prattrs-fedora test3]# du -h
> 13M    .
> [root@prattrs-fedora test3]#
> 
> I then did a test where I ran some producers in Java JMS for a while without any consumers
running:
> 
>                                                                                     
                           TextMessage msg = sendSession.createTextMessage(testContext.getPrefix()
>                                                                                     
                                                           + RandomUtils.randomAlphaNumericString(4085));
>                                                                                     
                           producer.send(msg, DeliveryMode.PERSISTENT, Message.DEFAULT_PRIORITY,
>                                                                                     
                                                           Message.DEFAULT_TIME_TO_LIVE);
> 
> Unsurprisingly, my journal quickly filled up and the broker showed this in logs:
> 
> Jul 23 17:29:32 localhost qpidd[2550]: 2009-07-23 17:29:32 error Failed to prepare: Journal
full on queue "test3". (JournalImpl.cpp:586)
> Jul 23 17:29:32 localhost qpidd[2550]: 2009-07-23 17:29:32 critical Journal "test3":
Journal full on queue "test3".
> Jul 23 17:29:32 localhost qpidd[2550]: 2009-07-23 17:29:32 error Error completing xid
yu\x00\x00\x00\x00\x00\x00\x97\xD6\xA9aP\x18IM\xB6\x91\xFA\xF1\xE6\x18}W: Journal full on
queue "test3". (JournalImpl.cpp:586)
> Jul 23 17:29:32 localhost qpidd[2550]: 2009-07-23 17:29:32 error Commit failed with exception:
Journal full on queue "test3". (JournalImpl.cpp:586)
> Jul 23 17:29:32 localhost qpidd[2550]: 2009-07-23 17:29:32 error Execution exception:
internal-error: Commit failed (qpid/broker/SemanticState.cpp:123)
> Jul 23 17:29:32 localhost qpidd[2550]: 2009-07-23 17:29:32 error Channel exception: not-attached:
Channel 0 is not attached (qpid/amqp_0_10/SessionHandler.cpp:40)
> Jul 23 17:29:33 localhost qpidd[2550]: 2009-07-23 17:29:33 critical Journal "test3":
Journal full on queue "test3".
> Jul 23 17:29:33 localhost qpidd[2550]: 2009-07-23 17:29:33 error Unexpected exception:
Journal full on queue "test3". (JournalImpl.cpp:586)
> Jul 23 17:29:33 localhost qpidd[2550]: 2009-07-23 17:29:33 error Connection 153.32.227.108:57837
closed by error: Journal full on queue "test3". (JournalImpl.cpp:586)(501)
> 
> I can sort of understand this, although it means flow-to-disk is not functioning for
my queue, I suppose. 

As above, the persistent messages would always be written to the journal 
and it has a fixed size.

The 'flow-to-disk' policy is probably confusingly named and inadequately 
described. It really just releases the message content from memory when 
a queue hits a particular limit; where those messages are durable anyway 
  nothing else is done. If however the messages are transient they are 
stored elsewhere and can then be reloaded for delivery.

> However, it turns out that I can't restart the broker either:
> 
> Jul 23 17:40:00 localhost qpidd[6303]: 2009-07-23 17:40:00 notice Store module initialized;
dir=/var/lib/qpidd
> Jul 23 17:40:00 localhost qpidd[6303]: 2009-07-23 17:40:00 notice Journal "test1": Created
> Jul 23 17:40:00 localhost qpidd[6303]: 2009-07-23 17:40:00 notice Journal "test2": Created
> Jul 23 17:40:00 localhost qpidd[6303]: 2009-07-23 17:40:00 warning Journal "test2": Recovery
found 12 files (different from --num-jfiles value of 8).
> Jul 23 17:40:00 localhost qpidd[6303]: 2009-07-23 17:40:00 warning Journal "test2": Recovery
found file size = 12 (different from --jfile-size-pgs value of 24).
> Jul 23 17:40:00 localhost qpidd[6303]: 2009-07-23 17:40:00 notice Journal "test3": Created
> Jul 23 17:40:01 localhost qpidd[6303]: 2009-07-23 17:40:01 critical Daemon startup failed:
Queue test3: recoverQueues() failed: jexception 0x0205 jcntl::recover() threw JERR_JCNTL_RECOVERJFULL:
Journal data files full, cannot write. (MessageStoreImpl.cpp:785)
> Jul 23 17:40:01 localhost qpidd[6302]: 2009-07-23 17:40:01 critical Broker start-up failed:
Daemon startup failed: Queue test3: recoverQueues() failed: jexception 0x0205 jcntl::recover()
threw JERR_JCNTL_RECOVERJFULL: Journal data files full, cannot write. (MessageStoreImpl.cpp:785)
> 
> My client jars are qpid-client-M5.1.jar and qpid-common-M5.1.jar.
> 
> Thanks in advance to anyone who can help.   Questions are listed above.
> 
> Sandy
> 
> 
> 
> 
> 


---------------------------------------------------------------------
Apache Qpid - AMQP Messaging Implementation
Project:      http://qpid.apache.org
Use/Interact: mailto:users-subscribe@qpid.apache.org


Mime
View raw message