mqtt_node keeping large amount of connection details in memory #2688

johanrhodin · 2020-12-17T21:25:12Z

johanrhodin
Dec 17, 2020

As reported in rabbitmq-users thread "High memory consumption (and message queue) in mqtt_node" we see RabbitMQ consuming more and more memory and never draining the Erlang mailbox.

We've created a repo that recreates the issue with a high likelyhood by creating a connection, channel, consumer and queue per connection. One can tune the connection to say 10k, 20k, etc until the situation is triggered. The repo is here: mqtt-connections

In addition to the screenshots attached in rabbitmq-users mail thread this is what the stack trace looks like

Answered by michaelklishin

Dec 21, 2020

#2692 seems to address this.

View full answer

carlhoerberg · 2020-12-17T21:37:32Z

carlhoerberg
Dec 17, 2020

run node churn.js mqtt://guest:guest@localhost 1 and see how the ra_log_ets grows indefinitely

0 replies

kjnilsson · 2020-12-17T21:39:02Z

kjnilsson
Dec 17, 2020
Maintainer

What WAL size are you using? See: https://www.rabbitmq.com/mqtt.html#consensus

…

On Thu, 17 Dec 2020 at 21:37, Carl Hörberg ***@***.***> wrote: run node churn.js ***@***.*** 1 and see how the ra_log_ets grows indefinitely — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#2688 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAJAHFDMZZEF35UC7FWALL3SVJ225ANCNFSM4VAIPAXQ> .

-- *Karl Nilsson*

0 replies

carlhoerberg · 2020-12-17T22:06:06Z

carlhoerberg
Dec 17, 2020

tried with 64 MB, no difference

0 replies

carlhoerberg · 2020-12-17T22:17:34Z

carlhoerberg
Dec 17, 2020

rabbitmq config, to make high MQTT connection count possible:

[
  {credentials_obfuscation, [{iterations, 1}, {hash, 'sha256'}, {cipher, 'aes_cbc128'}]},
  {rabbitmq_mqtt, [
    {tcp_listen_options, [
      {backlog, 4096},
      {sndbuf, 4096},
      {recbuf, 4096}
    ]}
  ]},
  {rabbitmq_management, [
    {rates_mode, none},
    {disable_stats, true},
    {enable_queue_totals, true}
  ]}
].

then run:
node app.js mqtt://guest:guest@localhost 10000, when they're up, close the application so that all connections closes. Now monitor the inbox of the mqtt_node process, it takes a very long time before it has reaches zero, if you continue to open/close connection it will grow indefinitely, eating GB after GB of RAM.

The stack trace indicates that it's mostly stuck in this function:

rabbitmq-server/deps/rabbitmq_mqtt/src/mqtt_machine.erl

Lines 72 to 83 in e3bbdfe

    
           apply(Meta, {down, DownPid, _}, #machine_state{client_ids = Ids} = State0) -> 
        
               Ids1 = maps:filter(fun (_ClientId, Pid) when Pid =:= DownPid -> 
        
                                          false; 
        
                                       (_, _) -> 
        
                                          true 
        
                                  end, Ids), 
        
               State = State0#machine_state{client_ids = Ids1}, 
        
               Delta = maps:keys(Ids) -- maps:keys(Ids1), 
        
               Effects = lists:map(fun(Id) -> 
        
                             [{mod_call, rabbit_log, debug, 
        
                               ["MQTT connection with client id '~s' failed", [Id]]}] end, Delta), 
        
               {State, ok, Effects ++ snapshot_effects(Meta, State)};

3 replies

kjnilsson Dec 21, 2020
Maintainer

ok so that is the function that is handling the down messages that arise from shutting each connection, I mean it isn't super optimised for sure. do you log at debug level? does it behave any better if you don't?

kjnilsson Dec 21, 2020
Maintainer

Ok I've done a first-pass optimisation of this function if you feel like testing it: https://github.com/rabbitmq/rabbitmq-server/tree/mqtt-machine-opt

kjnilsson Dec 21, 2020
Maintainer

hah a bit too quick, just pushed a fix

carlhoerberg · 2020-12-17T22:58:30Z

carlhoerberg
Dec 17, 2020

I do see a difference with a lower wal_max_size_bytes, the each mqtt_node ets table is smaller, but there are many of them instead. Total seems to be the same.

0 replies

carlhoerberg · 2020-12-17T23:10:25Z

carlhoerberg
Dec 17, 2020

Attaching the crash.log.gz

0 replies

carlhoerberg · 2020-12-17T23:35:04Z

carlhoerberg
Dec 17, 2020

The multiple mqtt_node ets tables seems to be cleared up when the inbox for mqtt_node is drained (which takes a long time even on an idle machine with no connections, after opened and closed 10 000 connections), but the mqtt_process was still using a lot of memory until the process was manually GCed.

0 replies

carlhoerberg · 2020-12-17T23:37:08Z

carlhoerberg
Dec 17, 2020

Now, when restarting the server after opened the 10000 connections and then closed them, always results in a failed boot:

[error] <0.18031.1> CRASH REPORT Process <0.18031.1> with 0 neighbours exited with reason: {timeout,{gen_statem,
@carl-xps13-fedora'},trigger_election,5000]}} in application_master:init/4 line 138
[info] <0.44.0> Application rabbitmq_mqtt exited with reason: {timeout,{gen_statem,call,[{mqtt_node,'rabbit@carl
election,5000]}}
[error] <0.17838.1> BOOT FAILED
[error] <0.17838.1> ===========
[info] <0.44.0> Application rabbitmq_mqtt exited with reason: {timeout,{gen_statem,call,[{mqtt_node,'rabbit@carl
election,5000]}}
[error] <0.17838.1> Error during startup: {error,
[error] <0.17838.1>                        {rabbitmq_mqtt,
[error] <0.17838.1>                         {bad_return,
[error] <0.17838.1>                          {{rabbit_mqtt,start,[normal,[]]},
[error] <0.17838.1>                           {'EXIT',
[error] <0.17838.1>                            {timeout,
[error] <0.17838.1>                             {gen_statem,call,
[error] <0.17838.1>                              [{mqtt_node,'rabbit@carl-xps13-fedora'},
[error] <0.17838.1>                               trigger_election,5000]}}}}}}}

Nothing but deleting the quorum directory seems to get it moving.

0 replies

kjnilsson · 2020-12-18T06:59:37Z

kjnilsson
Dec 18, 2020
Maintainer

I will take a closer look next week. What kind of disks are you using?

On Thu, 17 Dec 2020 at 23:37, Carl Hörberg ***@***.***> wrote: Now, when restarting the server after opened the 10000 connections and then closed them, always results in a failed boot: [error] <0.18031.1> CRASH REPORT Process <0.18031.1> with 0 neighbours exited with reason: {timeout,{gen_statem, @carl-xps13-fedora'},trigger_election,5000]}} in application_master:init/4 line 138 [info] <0.44.0> Application rabbitmq_mqtt exited with reason: ***@***.*** election,5000]}} [error] <0.17838.1> BOOT FAILED [error] <0.17838.1> =========== [info] <0.44.0> Application rabbitmq_mqtt exited with reason: ***@***.*** election,5000]}} [error] <0.17838.1> Error during startup: {error, [error] <0.17838.1> {rabbitmq_mqtt, [error] <0.17838.1> {bad_return, [error] <0.17838.1> {{rabbit_mqtt,start,[normal,[]]}, [error] <0.17838.1> {'EXIT', [error] <0.17838.1> {timeout, [error] <0.17838.1> {gen_statem,call, [error] <0.17838.1> ***@***.***'}, [error] <0.17838.1> trigger_election,5000]}}}}}}} Nothing but deleting the quorum directory seems to get it moving. — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#2688 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AAJAHFCTI3C6JXDY65OUCMTSVKI3DANCNFSM4VAIPAXQ> .

-- *Karl Nilsson*

0 replies

carlhoerberg · 2020-12-18T09:08:15Z

carlhoerberg
Dec 18, 2020

We've tried with AWS GP2, local SSD and RAM disk, no difference, no real disk usage anyway, just a single core very busy

…

On Fri, 18 Dec 2020, 07:59 Karl Nilsson, ***@***.***> wrote: I will take a closer look next week. What kind of disks are you using? On Thu, 17 Dec 2020 at 23:37, Carl Hörberg ***@***.***> wrote: > Now, when restarting the server after opened the 10000 connections and > then closed them, always results in a failed boot: > > [error] <0.18031.1> CRASH REPORT Process <0.18031.1> with 0 neighbours exited with reason: {timeout,{gen_statem, > @carl-xps13-fedora'},trigger_election,5000]}} in application_master:init/4 line 138 > [info] <0.44.0> Application rabbitmq_mqtt exited with reason: ***@***.*** > election,5000]}} > [error] <0.17838.1> BOOT FAILED > [error] <0.17838.1> =========== > [info] <0.44.0> Application rabbitmq_mqtt exited with reason: ***@***.*** > election,5000]}} > [error] <0.17838.1> Error during startup: {error, > [error] <0.17838.1> {rabbitmq_mqtt, > [error] <0.17838.1> {bad_return, > [error] <0.17838.1> {{rabbit_mqtt,start,[normal,[]]}, > [error] <0.17838.1> {'EXIT', > [error] <0.17838.1> {timeout, > [error] <0.17838.1> {gen_statem,call, > [error] <0.17838.1> ***@***.***'}, > [error] <0.17838.1> trigger_election,5000]}}}}}}} > > Nothing but deleting the quorum directory seems to get it moving. > > — > You are receiving this because you commented. > > > Reply to this email directly, view it on GitHub > < #2688 (comment) >, > or unsubscribe > < https://github.com/notifications/unsubscribe-auth/AAJAHFCTI3C6JXDY65OUCMTSVKI3DANCNFSM4VAIPAXQ > > . > -- *Karl Nilsson* — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#2688 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AABL6TW4SJHS2GM2DJEJA4DSVL4WPANCNFSM4VAIPAXQ> .

0 replies

carlhoerberg · 2020-12-21T12:25:15Z

carlhoerberg
Dec 21, 2020

Awesome! Will try it out in a bit

…

On Mon, Dec 21, 2020 at 1:16 PM Karl Nilsson ***@***.***> wrote: hah a bit too quick, just pushed a fix — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#2688 (reply in thread)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AABL6TWRLMKDNPUYM3VVRETSV44APANCNFSM4VAIPAXQ> .

8 replies

kjnilsson Dec 21, 2020
Maintainer

ok thanks for testing! I will prepare a patch with an optimised mqtt machine, I think I will do the full, proper optimisation and check if there are any other rough edges in the machine.

michaelklishin Dec 21, 2020
Maintainer

@kjnilsson so there are more changes coming? @carlhoerberg it would be great if you could help us verify more versions before we adopt it for 3.8.10 (which is almost ready to ship and is mostly delayed because of a very PTO-heavy season)

kjnilsson Dec 21, 2020
Maintainer

@michaelklishin yes there will be more changes, I can get it down from 4s to a few ms for 10000 downs so I think it's worth it

carlhoerberg Dec 21, 2020

sure, but "verify more versions", of rabbitmq or of tests cases that replicate the problem?

kjnilsson Dec 21, 2020
Maintainer

I've created a PR now: #2692

carlhoerberg · 2020-12-21T12:57:16Z

carlhoerberg
Dec 21, 2020

Just tested it, my initial trials shows a huge difference!

…

On Mon, Dec 21, 2020 at 1:45 PM Karl Nilsson ***@***.***> wrote: I also have an approach that can bring the same test down to a few ms but it will require a bit more work and testing. — You are receiving this because you commented. Reply to this email directly, view it on GitHub <#2688 (reply in thread)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AABL6TSKK6LOY6IUX53LOE3SV47N7ANCNFSM4VAIPAXQ> .

0 replies

michaelklishin · 2020-12-21T18:37:21Z

michaelklishin
Dec 21, 2020
Maintainer

#2692 seems to address this.

0 replies

johanrhodin · 2020-12-21T19:11:10Z

johanrhodin
Dec 21, 2020
Author

We'll take a build with #2692 in it for a few spins.

0 replies

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

mqtt_node keeping large amount of connection details in memory #2688

{{title}}

Replies: 14 comments 11 replies

{{title}}

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

Select a reply

mqtt_node keeping large amount of connection details in memory #2688

Replies: 14 comments · 11 replies

kjnilsson Dec 17, 2020 Maintainer

kjnilsson Dec 21, 2020 Maintainer

kjnilsson Dec 21, 2020 Maintainer

kjnilsson Dec 21, 2020 Maintainer

kjnilsson Dec 18, 2020 Maintainer

kjnilsson Dec 21, 2020 Maintainer

michaelklishin Dec 21, 2020 Maintainer

kjnilsson Dec 21, 2020 Maintainer

kjnilsson Dec 21, 2020 Maintainer

michaelklishin Dec 21, 2020 Maintainer

johanrhodin Dec 21, 2020 Author

Replies: 14 comments 11 replies

kjnilsson
Dec 17, 2020
Maintainer

kjnilsson Dec 21, 2020
Maintainer

kjnilsson Dec 21, 2020
Maintainer

kjnilsson Dec 21, 2020
Maintainer

kjnilsson
Dec 18, 2020
Maintainer

kjnilsson Dec 21, 2020
Maintainer

michaelklishin Dec 21, 2020
Maintainer

kjnilsson Dec 21, 2020
Maintainer

kjnilsson Dec 21, 2020
Maintainer

michaelklishin
Dec 21, 2020
Maintainer

johanrhodin
Dec 21, 2020
Author