Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Lazy queue consume too much memory and hits an alarm #59

Closed
lyrixx opened this issue Feb 6, 2020 · 14 comments
Closed

Lazy queue consume too much memory and hits an alarm #59

lyrixx opened this issue Feb 6, 2020 · 14 comments
Labels

Comments

@lyrixx
Copy link

@lyrixx lyrixx commented Feb 6, 2020

Hello.

A bit of history:

I have a queue with many (100K) big (few kb to 5mb) message in it.
The queue is locked from time to time.
And the consumer itself is locked, so my system is broken.

I read many docs on your website (very nice work, thanks), and issues on github, and I understand what was the cause.

The queue was "normal", and RabbitMQ hit the wall of vm_memory_high_watermark.absolute so it needs to vacuum. This is perfectly fine. (Note: sometime the GC never ends 😬 but that's another topic)

I can not loose message, so my queue is durable, and I publish with delivery_mode=2. So my message will reach the disk anyway

Then I discover lazy queue. This is exactly what I need

Lazy Queue and Memory

Lazy queue does not keep messages in RAM, but put messages on the disk.

I made a small script to publish messages of ~1Mb. It display a . for each published message
or a X if the publishing took more than 1s.
There are no consumer on this queue.

This is what it looks like:
.....................................................................................................................................................................
..........................................................................................................................................................................
..........................................................................................................................................................................
..........................................................................................................................................................................
..........................................................................................................................................................................
......................................................................................................................................................                    
..........................................................................................................................................................................
..........................................................................................................................................................................
..................................................................................................................................................X.................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................
.................................................................................................................................................................................................................X..........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................X...........................
....................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................X............................X......................................................................................................................................................................................................................................................................................................................................................................................................
.................................................................................................................................................................................................................X...........................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................X..........................................................................................................................................................................................................................................................
........X................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................X..............................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................
.................................................................................................................................................................................X.......................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................X..............................................................................................................................................................................................
.........................................................................................................................................................................................................................................................................................................................................................................................................................X..............................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................
......................................................................................................................................................................................................X.........X.......................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................................X.....................................................................................................................................................................................X.........

As you can see, there is a lot of X. Each X can took from 1 to 10s and sometime even more.

During the ingest, RabbitMQ consume too much memory

image

I don't why it consumes so much memory, since everything is written to disk directly.
So the memory alarm wake up and a GC is involved.
So everything is blocked for a while (even the consumer).


Is it possible to not consume memory, to not trigger the memory alarm and so avoid the GC?

@lukebakken lukebakken transferred this issue from rabbitmq/tgir Feb 6, 2020
@michaelklishin

This comment has been minimized.

Copy link
Member

@michaelklishin michaelklishin commented Feb 6, 2020

We need server logs to confirm that there is an alarm and a definition export (or an executable way to reproduce) in order to confirm that the queue is in lazy mode.

There is a diagnostics command that produces a memory usage breakdown. We need that information as well or we wouldn't be able to help you.

@lukebakken

This comment has been minimized.

Copy link
Member

@lukebakken lukebakken commented Feb 6, 2020

Is your disk fast enough to keep up with the incoming data rate?

@lyrixx

This comment has been minimized.

Copy link
Author

@lyrixx lyrixx commented Feb 6, 2020

Hello.

I made a reproducer for you. I thought it will be easier to confirm my words
https://gist.github.com/lyrixx/48063c011134e58562b648bb4c1e63f8
I used Docker & PHP, but it should not be a big deal. If you have any issue,
I will glad to help you.

We need server logs to confirm that there is an alarm

Here are some logs
rabbitmq_1  | **********************************************************
rabbitmq_1  | *** Publishers will be blocked until this alarm clears ***
rabbitmq_1  | **********************************************************
rabbitmq_1  | 2020-02-06 17:01:41.726 [info] <0.283.0> vm_memory_high_watermark clear. Memory used:1056669696 allowed:1073741824
rabbitmq_1  | 2020-02-06 17:01:41.726 [warning] <0.281.0> memory resource limit alarm cleared on node rabbit@6bc143c9ad1f
rabbitmq_1  | 2020-02-06 17:01:41.727 [warning] <0.281.0> memory resource limit alarm cleared across the cluster
rabbitmq_1  | 2020-02-06 17:01:47.732 [info] <0.283.0> vm_memory_high_watermark set. Memory used:1395343360 allowed:1073741824
rabbitmq_1  | 2020-02-06 17:01:47.732 [warning] <0.281.0> memory resource limit alarm set on node rabbit@6bc143c9ad1f.
rabbitmq_1  | 
rabbitmq_1  | **********************************************************
rabbitmq_1  | *** Publishers will be blocked until this alarm clears ***
rabbitmq_1  | **********************************************************
rabbitmq_1  | 2020-02-06 17:01:54.741 [info] <0.283.0> vm_memory_high_watermark clear. Memory used:1027305472 allowed:1073741824
rabbitmq_1  | 2020-02-06 17:01:54.741 [warning] <0.281.0> memory resource limit alarm cleared on node rabbit@6bc143c9ad1f
rabbitmq_1  | 2020-02-06 17:01:54.741 [warning] <0.281.0> memory resource limit alarm cleared across the cluster
rabbitmq_1  | 2020-02-06 17:01:55.403 [info] <0.1203.0> closing AMQP connection <0.1203.0> (172.18.0.2:52942 -> 172.18.0.3:5672, vhost: '/', user: 'guest')
rabbitmq_1  | 2020-02-06 17:01:55.742 [info] <0.283.0> vm_memory_high_watermark set. Memory used:1484963840 allowed:1073741824
rabbitmq_1  | 2020-02-06 17:01:55.743 [warning] <0.281.0> memory resource limit alarm set on node rabbit@6bc143c9ad1f.
rabbitmq_1  | 
rabbitmq_1  | **********************************************************
rabbitmq_1  | *** Publishers will be blocked until this alarm clears ***
rabbitmq_1  | **********************************************************
rabbitmq_1  | 2020-02-06 17:02:05.752 [info] <0.283.0> vm_memory_high_watermark clear. Memory used:1033019392 allowed:1073741824
rabbitmq_1  | 2020-02-06 17:02:05.752 [warning] <0.281.0> memory resource limit alarm cleared on node rabbit@6bc143c9ad1f
rabbitmq_1  | 2020-02-06 17:02:05.752 [warning] <0.281.0> memory resource limit alarm cleared across the cluster

and a definition export

Here are and export of the definition
{
   "topic_permissions" : [],
   "vhosts" : [
      {
         "name" : "/"
      }
   ],
   "global_parameters" : [
      {
         "value" : "rabbit@6bc143c9ad1f",
         "name" : "cluster_name"
      }
   ],
   "rabbitmq_version" : "3.8.2",
   "parameters" : [],
   "users" : [
      {
         "tags" : "administrator",
         "password_hash" : "oWv2b0vF1Pj/ggvHelXN8gHhjM2Q50Rd6mBdOI5CzxK8fObP",
         "name" : "guest",
         "hashing_algorithm" : "rabbit_password_hashing_sha256"
      }
   ],
   "policies" : [],
   "queues" : [
      {
         "arguments" : {
            "x-queue-mode" : "lazy"
         },
         "auto_delete" : false,
         "durable" : true,
         "name" : "test",
         "vhost" : "/"
      }
   ],
   "bindings" : [
      {
         "destination" : "test",
         "arguments" : {},
         "destination_type" : "queue",
         "vhost" : "/",
         "source" : "test",
         "routing_key" : "test"
      }
   ],
   "exchanges" : [
      {
         "internal" : false,
         "arguments" : {},
         "name" : "test",
         "type" : "direct",
         "vhost" : "/",
         "auto_delete" : false,
         "durable" : false
      }
   ],
   "permissions" : [
      {
         "write" : ".*",
         "read" : ".*",
         "configure" : ".*",
         "vhost" : "/",
         "user" : "guest"
      }
   ],
   "rabbit_version" : "3.8.2"
}

There is a diagnostics command that produces a memory usage breakdown. We need that information as well or we wouldn't be able to help you.

Reporting memory breakdown on node rabbit@6bc143c9ad1f...                                                                                                                 
binary: 0.8642 gb (61.08%)                                                                                                                                                
allocated_unused: 0.458 gb (32.37%)                                                                                                                                       
code: 0.03 gb (2.12%)                                                                                                                                                     
other_system: 0.0271 gb (1.92%)                                                                                                                                           
other_proc: 0.0232 gb (1.64%)                                                                                                                                             
other_ets: 0.0031 gb (0.22%)                                                                                                                                              
queue_procs: 0.0026 gb (0.18%)                                                                                                                                            
msg_index: 0.0022 gb (0.16%)                                                                                                                                              
plugins: 0.0017 gb (0.12%)                                                                                                                                                
atom: 0.0015 gb (0.11%)                                                                                                                                                   
mgmt_db: 0.0006 gb (0.04%)                                                                                                                                                
metrics: 0.0002 gb (0.02%)                                                                                                                                                
connection_other: 0.0001 gb (0.01%)                                                                                                                                       
mnesia: 0.0001 gb (0.01%)
quorum_ets: 0.0 gb (0.0%)
connection_readers: 0.0 gb (0.0%)
connection_channels: 0.0 gb (0.0%)
connection_writers: 0.0 gb (0.0%)
queue_slave_procs: 0.0 gb (0.0%)
quorum_queue_procs: 0.0 gb (0.0%)
reserved_unallocated: 0.0 gb (0.0%)

Is your disk fast enough to keep up with the incoming data rate?

I ran this benchmark from a DELL XPS 13" 2019. It has a SSD.
I don't know if it's enough for but but it's pretty fast. It's totally able to ingest this workload

@michaelklishin

This comment has been minimized.

Copy link
Member

@michaelklishin michaelklishin commented Feb 6, 2020

So 93% of memory used is allocated in the binary heap or preallocated by the runtime. RabbitMQ does not control either of those, the runtime does, and there are quite a few allocator settings to tweak and try.

@essen @gerhard @lukebakken might have more specific settings to try or ways to collect more metrics that would help us reason about possible allocator memory fragmentation.

@michaelklishin

This comment has been minimized.

Copy link
Member

@michaelklishin michaelklishin commented Feb 6, 2020

Closing as this has nothing to do with lazy queues but you are welcome to continue discussing this, of course.

@lyrixx

This comment has been minimized.

Copy link
Author

@lyrixx lyrixx commented Feb 6, 2020

I observed the same behavior on default queue too. But since lazy queue does/should not use RAM, I reported it.

I don't understand why it uses this amount of memory, and how I can avoid this.

It's a bit naive, but I thought the memory consumption would be linear, low, and stable. ATM it keeps increasing when data is coming. It does not explode because rabbitmq reachs the threshold and blocks the publisher then run the GC, and resume data ingestion.

I'm gonna read the documentation you give me, thanks.

But it looks like something is strange here.

(If any-one have a quick-win for me, I take it 🙏 😄 )

@michaelklishin michaelklishin changed the title Lazy queue consume too much memory and lock itself Lazy queue consume too much memory and hits an alarm Feb 6, 2020
@michaelklishin

This comment has been minimized.

Copy link
Member

@michaelklishin michaelklishin commented Feb 6, 2020

As I tried to explain, according to the data you have shared, it is the runtime's memory allocator and binary heap that consume 93% of memory on the node. Quorum queues do not and cannot control that behavior.

Finding a "quick win" would be a matter of trying different memory allocator flags. We have tried to update the defaults to be generally suitable but in some environments this behavior is known. We don't know the root cause at the moment. Can this be reproduced with an example Docker Compose setup we could run?

@lukebakken

This comment has been minimized.

Copy link
Member

@lukebakken lukebakken commented Feb 6, 2020

But since lazy queue does/should not use RAM

Memory will be used to buffer incoming data until it can be written to disk. RabbitMQ does not have the ability (at this time) to directly stream data from the TCP buffer straight to the filesystem.

@gerhard

This comment has been minimized.

Copy link
Member

@gerhard gerhard commented Feb 6, 2020

If you are running this in Docker or K8S, the quick win would be to not use a bridged network - use the host network.

The second quick win is to use a fast disk (SSD+NVME) and ensure that you are not saturating its IOPS or throughput.

Until the message hits the disk, it will jump through many buffers: Erlang ports (this is how an Erlang process communicates with a TCP socket), a handful of Erlang processes (connection, channel, queue etc.), and eventually the persistent message store (also an Erlang process) at which point fsync gets called and the message gets written to disk.

Once this is done, garbage collection needs to runs on every single Erlang process that referenced the message. Since GC is per process, not for the entire VM as seen in Ruby, Java etc., until every single Erlang process dereferences the pointer to the message, this message will not be cleared from the binary heap. As I understand, this is what accounts for 93% of your Rabbit's memory usage.

If there is a consumer that is getting this message delivered, then there will be even more Erlang processes referencing the message in the binary heap and thus forcing it to remain in memory.

I encourage you to re-run your benchmark via https://github.com/rabbitmq/tgir/blob/S01E01/s01/e01/Makefile#L57-L64 and share your findings. Bonus points if you can translate your workload into PerfTest arguments: https://github.com/rabbitmq/tgir/blob/S01E01/s01/e01/Makefile#L163-L205.

I will keep your use-case in mind while working on rabbitmq/tgir#5, thanks for sharing!

@lyrixx

This comment has been minimized.

Copy link
Author

@lyrixx lyrixx commented Feb 7, 2020

@gerhard Thanks for your very detailed answer 👍

Quorum queues do not and cannot control that behavior.

🤔 I'm not using a qorum queue. It's a "normal" queue.

Can this be reproduced with an example Docker Compose setup we could run?

Sure, I posted it in my previous comment. https://gist.github.com/lyrixx/48063c011134e58562b648bb4c1e63f8
As you can see, this is something really straightforward.

Memory will be used to buffer incoming data until it can be written to disk. RabbitMQ does not have the ability (at this time) to directly stream data from the TCP buffer straight to the filesystem.

Yes I understand that. But since my script (mono threaded, no concurrence, no async) published messages one by one the buffer can not / should not contains more than one message.

ATM, I'm able to publish ~1K messages (it's about 1Gb of messages) and then publishing stop for ~10s.
During the publishing, memory keep increasing.
During the blocking, memory is released

If you are running this in Docker or K8S, the quick win would be to not use a bridged network - use the host network.

I just tried, and it does not change that much.

The second quick win is to use a fast disk (SSD+NVME) and ensure that you are not saturating its IOPS or throughput.

I have an SSD

More over, RabbitMQ can ingest 1K messages before stopping. Message are already on the disk, right? It puts message by message on disk. I said that, because RabbitMQ guarantee no data lose. So it tell me that the message has been persisted, I think the message has been saved to the disk. Am I wrong?

BUT I ran some bench to be sure:

☭:~$ time dd if=/dev/zero of=1G.data count=1024 bs=1048570
1024+0 records in
1024+0 records out
1073735680 bytes (1.1 GB, 1.0 GiB) copied, 0.778864 s, 1.4 GB/s
dd if=/dev/zero of=1G.data count=1024 bs=1048570  0.00s user 0.78s system 99% cpu 0.782 total
☭:~$ time dd if=/dev/zero of=1G.data count=1024 bs=1048570
1024+0 records in
1024+0 records out
1073735680 bytes (1.1 GB, 1.0 GiB) copied, 1.17465 s, 914 MB/s
dd if=/dev/zero of=1G.data count=1024 bs=1048570  0.00s user 1.04s system 76% cpu 1.362 total
☭:~$ time dd if=/dev/zero of=1G.data count=1024 bs=1048570
1024+0 records in
1024+0 records out
1073735680 bytes (1.1 GB, 1.0 GiB) copied, 1.47228 s, 729 MB/s
dd if=/dev/zero of=1G.data count=1024 bs=1048570  0.00s user 1.28s system 78% cpu 1.630 total
☭:~$ time dd if=/dev/zero of=1G.data count=1024 bs=1048570
1024+0 records in
1024+0 records out
1073735680 bytes (1.1 GB, 1.0 GiB) copied, 1.16887 s, 919 MB/s

This is not super stable (this is my laptop) but the disk can ingest at least 500Mb/sec

I encourage you to re-run your benchmark via https://github.com/rabbitmq/tgir/blob/S01E01/s01/e01/Makefile#L57-L64 and share your findings. Bonus points if you can translate your workload into PerfTest arguments: https://github.com/rabbitmq/tgir/blob/S01E01/s01/e01/Makefile#L163-L205.

I will try, but I can not guarantee anything. Sorry

@lukebakken

This comment has been minimized.

Copy link
Member

@lukebakken lukebakken commented Feb 7, 2020

I'm assuming that Docker image uses at least version 22.2 of Erlang.

Your dd test does not test synchronous writes (conv=sync is needed). When you publish messages as persistent RabbitMQ ensures they are synced to disk. The fio utility is much better for testing synchronous disk write performance anyway.

If I have time I'll try to reproduce this in my home environment. If you are running your benchmark on the same server as RabbitMQ the two processes will compete for resources.

@lukebakken

This comment has been minimized.

Copy link
Member

@lukebakken lukebakken commented Feb 10, 2020

I can't reproduce this behavior in my home environment:

  • RabbitMQ 3.8.2 running on FreeBSD 12, using Erlang 22.2.6. I created a classic, lazy queue named test
  • PerfTest running on Windows 10 running with these arguments (shell is powershell):
mvn compile
mvn 'exec:java' '-Dexec.mainClass=com.rabbitmq.perf.PerfTest' '-Dexec.args=--uri amqp://guest:guest@ravel:5672/%2f --flag persistent --producers 1 --consumers 0 --size 1000000 --predeclared --queue test'

I published 70K+ messages to the lazy queue. Avg publish rate was about 117 messages per second. Memory never exceeded 175MiB for RabbitMQ.

In my environment, the server running RabbitMQ is much slower hardware than yours. It is an Intel i3 CPU with 7200RPM disks in a ZFS mirror configuration. I am also not using Docker, nor am I running the test program (PerfTest) on the same system as RabbitMQ.

I suspect your issue is specific to Docker. Please re-run your test without using Docker, and run your test PHP program on a different system. Thanks.

@lyrixx

This comment has been minimized.

Copy link
Author

@lyrixx lyrixx commented Feb 10, 2020

I don't have RabbmitMQ on my host. Is LXC allowed ?
I can install it if needed

@lukebakken

This comment has been minimized.

Copy link
Member

@lukebakken lukebakken commented Feb 10, 2020

RabbitMQ should work in LXC, however you may experience the same issues as with Docker (if that is the cause of your issue at all, which we don't know).

lazy queues are commonly used with RabbitMQ so if this were a serious, visible issue we would hear about it. That's why I suspect this is specific to your environment.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Linked pull requests

Successfully merging a pull request may close this issue.

None yet
4 participants
You can’t perform that action at this time.