[rabbitmq-discuss] Failed upgrade from 1.8.1 to 2.1.0
David King
At first (about 15:10 on the graph), almost all of the queues started growing. Consumers would hang, unaided by restarts. But some of the queues (like commenstree_q and register_vote_q) didn't have any trouble at all.
At about 15:50, after about 30 minutes of trying to figure out what was going on I restarted rabbit. This time, some of the queues that were uncomsumable before (like spam_q and corrections_q) were now working, but other queues (like indextank_changes) would still hang on consuming.
At 16:20 I gave up and started reverting back to the other queue machine (running rabbit 1.8.1). As that happened, some of the queues that were unconsumable finally started shrinkining and their consumers unhung. Some of them (newcomments_q) processed all of the items in the queue basically instantly, so this isn't a case of our own app not being able to keep up. By about 16:30 I'd completed moving back to the old machine.
Potentially relevant:
* commentstree_q has 4 consumers
* corrections_q has 1 consumer
* the one with the blacked out name has 1 consumer that runs from cron, not continuously
* indextank_changes has 2 consumers
* log_q has 1 consumer
* newcomments_q has 1 consumer
* register_vote_q has ~15 consumers
* scraper_q has 5 consumers
* solrsearch_changes has 1 consumer
* spam_q has 4 consumers
* usage_q has 2 consumers
I realise this may not be enough information, but the logs were basically empty for this period (they'd have occasional messages like "someone connected" and "someone disconnected" but nothing more useful). So what information can I gather beyond this that might help diagnose why rabbit 2.1.0 can't keep up but 1.8.1 can?
Also, this is unrelated, but I'd provisioned the new machine a couple of weeks ago, and it's been sitting literally 100% idle until I tried moving today. But look at its memory usage over the last week <http://i.imgur.com/M7x6m.png>. What on earth could it be doing that it's growing in memory when *not used*? This machine is identical to our other machines (it's an EC2 node from the same AMI), but only this node has this problem, and all it's running is rabbit.
_______________________________________________
rabbitmq-discuss mailing list
rabbitmq...@lists.rabbitmq.com
https://lists.rabbitmq.com/cgi-bin/mailman/listinfo/rabbitmq-discuss
Matthew Sackman
Glad you're well.
On Thu, Oct 07, 2010 at 05:32:36PM -0700, David King wrote:
> At first (about 15:10 on the graph), almost all of the queues started
> growing. Consumers would hang, unaided by restarts. But some of the
> queues (like commenstree_q and register_vote_q) didn't have any
> trouble at all.
Ok, how much memory is in the box, and what are the average sizes of
these messages? Are you setting the memory_high_watermark to anything
non-default (of 0.4)? When rabbit starts, there should be entries in the
logs saying things like:
=INFO REPORT==== 8-Oct-2010::12:47:52 ===
Memory limit set to 4816MB.
What does it say in your case?
I suspect that you're maybe hitting the memory high watermark - are
there any entries in the logs like:
=INFO REPORT==== 7-Oct-2010::17:41:43 ===
alarm_handler: {set,{vm_memory_high_watermark,[]}}
?
Also, are you publishing messages transient or persistent (what's the
delivery_mode when you publish messages)?. And your consumers that
blocked, are these the ones using basic.get or basic.consume? And are
they acking messages or using autoack? Are any of the consumers doing
any publishes too?
> At about 15:50, after about 30 minutes of trying to figure out what
> was going on I restarted rabbit. This time, some of the queues that
> were uncomsumable before (like spam_q and corrections_q) were now
> working, but other queues (like indextank_changes) would still hang on
> consuming.
Interesting. What actions other than basic.consume (I assume) are these
consumers doing when they connect? Do they try and redeclare the queue
or create any other resources?
> At 16:20 I gave up and started reverting back to the other queue
> machine (running rabbit 1.8.1). As that happened, some of the queues
> that were unconsumable finally started shrinkining and their consumers
> unhung. Some of them (newcomments_q) processed all of the items in the
> queue basically instantly, so this isn't a case of our own app not
> being able to keep up. By about 16:30 I'd completed moving back to the
> old machine.
Ok, what was the disk activity during this exercise in general? The new
persister is much better at coping with memory pressure. However, that
has a few interesting and possibly surprising facets:
1. Eventually, if memory pressure continues to build, all messages have
to be written to disk.
2. At no point do we want the queue to become unresponsive. This means
that we have to batch work, and actually start writing messages to disk
fairly early on, in the general scheme of things: we don't want to get
to the point where we suddenly realise we have to write out millions of
items to disk: we want a smooth transition to occur.
3. Short fast queues are prioritised. This is because they probably
won't be able to maintain their rates if they're having to go via the
disk, whereas slower queues probably can. That said, we work as hard as
possible to avoid having to do any reads until things get really bad,
memory wise. Most of the time, it should just be appends.
Of course, all of this is only relevant if you're actually seeing the
disk thrashing itself to death and you're running out of memory.
We have recently identified and fixed some memory issues with queues in
general, however, they're only really relevant if you're using thousands
of queues, so I don't think it's these that are biting you.
> Also, this is unrelated, but I'd provisioned the new machine a couple
> of weeks ago, and it's been sitting literally 100% idle until I tried
> moving today. But look at its memory usage over the last week
> <http://i.imgur.com/M7x6m.png>. What on earth could it be doing that
> it's growing in memory when *not used*? This machine is identical to
> our other machines (it's an EC2 node from the same AMI), but only this
> node has this problem, and all it's running is rabbit.
Now that is interesting. What version of Erlang are you running?
Matthew
David King
> these messages? Are you setting the memory_high_watermark to anything
> non-default (of 0.4)? When rabbit starts, there should be entries in the
> logs saying things like:
The messages average about 8 bytes (they are mostly IDs that look like "t3_abcde"). The machine has 7.5gb of RAM, and the log messages you describe look like:
=INFO REPORT==== 7-Oct-2010::15:54:19 ===
Limiting to approx 924 file handles (829 sockets)
=INFO REPORT==== 7-Oct-2010::15:54:19 ===
Memory limit set to 3081MB.
> I suspect that you're maybe hitting the memory high watermark - are
> there any entries in the logs like:
There are no messages mentioning vm_memory_high_watermark or alarms:
ri@q01:~/rabbitmq_server/log$ egrep -i '(alarm|memory)' *
rab...@q01.log:Memory limit set to 3081MB.
rab...@q01.log.1:Memory limit set to 3081MB.
rab...@q01.log.1:Memory limit set to 3081MB.
And as you can see in the memory graph I included at the end there, the bump at the end was this attempted upgrade, and the machine definitely didn't run out of RAM. But that "924 file handles" does look quite low, how can I increase that?
> Also, are you publishing messages transient or persistent (what's the
> delivery_mode when you publish messages)?. And your consumers that
> blocked, are these the ones using basic.get or basic.consume? And are
> they acking messages or using autoack? Are any of the consumers doing
> any publishes too?
Some messages are transient and some are persistent. The blocked queues appear to be a mix of basic.get and basic.consume. The consumers ack their own messages (not autoack). I don't think any of the consumers publish messages
> Interesting. What actions other than basic.consume (I assume) are these
> consumers doing when they connect? Do they try and redeclare the queue
> or create any other resources?
They do all try to redeclare all of the queues and bindings, yes
> Ok, what was the disk activity during this exercise in general?
I didn't get a note of it, but the CPU usage, including WAIT CPU, didn't noticeably increase (I have the CPU graph for that period and it's flat with respect to before, during, and after the upgrade), and I'd expect the WAIT to go up if the disk was swamped.
>> Also, this is unrelated, but I'd provisioned the new machine a couple
>> of weeks ago, and it's been sitting literally 100% idle until I tried
>> moving today. But look at its memory usage over the last week
>> <http://i.imgur.com/M7x6m.png>. What on earth could it be doing that
>> it's growing in memory when *not used*? This machine is identical to
>> our other machines (it's an EC2 node from the same AMI), but only this
>> node has this problem, and all it's running is rabbit.
> Now that is interesting. What version of Erlang are you running?
ri@q01:~/rabbitmq_server/log$ erl --version
Erlang R14B (erts-5.8.1) [source] [64-bit] [smp:2:2] [rq:2] [async-threads:0] [kernel-poll:false]
Thanks for the help so far :)
Matthew Sackman
On Fri, Oct 08, 2010 at 11:53:28AM -0700, David King wrote:
> And as you can see in the memory graph I included at the end there,
> the bump at the end was this attempted upgrade, and the machine
> definitely didn't run out of RAM. But that "924 file handles" does
> look quite low, how can I increase that?
ulimit -n and /etc/security/limits.conf
However, for the number of queues you have, 924 is more than plenty.
The rest of your details leave me puzzled. Is there any possibility of
you being able to attempt the migration again, but without any consumers
at all? - literally just duplicate all your incoming streams into a new
Rabbit? - I'm curious if the queues will continue to fill correctly for
some time before exhausting RAM. Also, during this time, the output of
"rabbitmqctl list_queues name backing_queue_status" would be useful.
I remember when I was in your office we talking briefly about the
monitoring you were doing, but I've since forgotten - how are the stats
for those graphs being obtained? - is something just shelling out to
rabbitmqctl or is something else going on or...?
Your graphs that you posted didn't include the unacknowledged_messages
field which is available from rabbitmqctl list_queues, or from
rabbitmqctl list_channels. Do you have that data for that period of
time?
Best wishes,
Matthew