moscajs / aedes

Barebone MQTT broker that can run on any stream server, the node way
MIT License
1.76k stars 228 forks source link

[question] Aedes Mongo Persistance making too many requests on client connection #559

Open mogupta opened 3 years ago

mogupta commented 3 years ago

Hi Here are the logs from a single client connecting to my aedes server . I have added debug logs to each mongodb persistance to see what db calls are being made, The reason for such inspection is high load on the db side with only ~2000 clients the client connects with clean = true;

authorize :- device-5fa4915fe3ead751dcc63e51 Aedes: sub by client (not sure why this call is being made, I don't want to retain subscriptions. let clients subscribe every time) Aedes: delWill Aedes: getWill Aedes: putWill client connected T2682131 Aedes: Outgoing stream Published $SYS/00382440-7836-4a47-a2d1-de5a146f9a9b/new/clients T2682131 by 32437 Aedes: Stored Retained Emitter /5fa4915fe3ead751dcc63e51 Emitter /5fa4915fe3ead751dcc63e51/update Emitter /5fa4915fe3ead751dcc63e51/newSchedule Emitter /5fa4915fe3ead751dcc63e51/removeSchedule Emitter /5fa4915fe3ead751dcc63e51/updateSchedule Emitter /5fa4915fe3ead751dcc63e51/restart Emitter /5fa4915fe3ead751dcc63e51/reset

Below mongo query is being made, not sure why you would want empty queries ? for each subscription , one query is made. From Mongo Debug logs issue initial query [{"find":"tinxy-mqtt-db.retained","limit":0,"skip":0,"query":{"topic":{}},"hint":null,"slaveOk":true,"readPreference":{"mode":"primary"}}]

Aedes: Create Retained Stream combi
Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Stored Retained Published /5fa4915fe3ead751dcc63e51/status 1 by 32437 Published /5fa4915fe3ead751dcc63e51/status 1 by 32437

robertsLando commented 3 years ago

Is clean flag set to true on clients connections?


Daniel

On 6 Nov 2020, at 01:54, Mohit notifications@github.com wrote:

 Hi Here are the logs from a single client connecting to my aedes server . I have added debug logs to each mongodb persistance to see what db calls are being made, The reason for such inspection is high load on the db side with only ~2000 clients the client connects with clean = true;

authorize :- device-5fa4915fe3ead751dcc63e51 Aedes: sub by client (not sure why this call is being made, I don't want to retain subscriptions. let clients subscribe every time) Aedes: delWill Aedes: getWill Aedes: putWill client connected T2682131 Aedes: Outgoing stream Published $SYS/00382440-7836-4a47-a2d1-de5a146f9a9b/new/clients T2682131 by 32437 Aedes: Stored Retained Emitter /5fa4915fe3ead751dcc63e51 Emitter /5fa4915fe3ead751dcc63e51/update Emitter /5fa4915fe3ead751dcc63e51/newSchedule Emitter /5fa4915fe3ead751dcc63e51/removeSchedule Emitter /5fa4915fe3ead751dcc63e51/updateSchedule Emitter /5fa4915fe3ead751dcc63e51/restart Emitter /5fa4915fe3ead751dcc63e51/reset

Below mongo query is being made, not sure why you would want empty queries ? for each subscription , one query is made. From Mongo Debug logs issue initial query [{"find":"tinxy-mqtt-db.retained","limit":0,"skip":0,"query":{"topic":{}},"hint":null,"slaveOk":true,"readPreference":{"mode":"primary"}}]

Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Stored Retained Published /5fa4915fe3ead751dcc63e51/status 1 by 32437 Published /5fa4915fe3ead751dcc63e51/status 1 by 32437

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or unsubscribe.

mogupta commented 3 years ago

Yes

On Fri, 6 Nov, 2020, 12:05 pm Daniel Lando, notifications@github.com wrote:

Is clean flag set to true on clients connections?


Daniel

On 6 Nov 2020, at 01:54, Mohit notifications@github.com wrote:

 Hi Here are the logs from a single client connecting to my aedes server . I have added debug logs to each mongodb persistance to see what db calls are being made, The reason for such inspection is high load on the db side with only ~2000 clients the client connects with clean = true;

authorize :- device-5fa4915fe3ead751dcc63e51 Aedes: sub by client (not sure why this call is being made, I don't want to retain subscriptions. let clients subscribe every time) Aedes: delWill Aedes: getWill Aedes: putWill client connected T2682131 Aedes: Outgoing stream Published $SYS/00382440-7836-4a47-a2d1-de5a146f9a9b/new/clients T2682131 by 32437 Aedes: Stored Retained Emitter /5fa4915fe3ead751dcc63e51 Emitter /5fa4915fe3ead751dcc63e51/update Emitter /5fa4915fe3ead751dcc63e51/newSchedule Emitter /5fa4915fe3ead751dcc63e51/removeSchedule Emitter /5fa4915fe3ead751dcc63e51/updateSchedule Emitter /5fa4915fe3ead751dcc63e51/restart Emitter /5fa4915fe3ead751dcc63e51/reset

Below mongo query is being made, not sure why you would want empty queries ? for each subscription , one query is made. From Mongo Debug logs issue initial query [{"find":"tinxy-mqtt-db.retained","limit":0,"skip":0,"query":{"topic":{}},"hint":null,"slaveOk":true,"readPreference":{"mode":"primary"}}]

Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Create Retained Stream combi Aedes: Stored Retained Published /5fa4915fe3ead751dcc63e51/status 1 by 32437 Published /5fa4915fe3ead751dcc63e51/status 1 by 32437

— You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub, or unsubscribe.

— You are receiving this because you authored the thread. Reply to this email directly, view it on GitHub https://github.com/moscajs/aedes/issues/559#issuecomment-722901914, or unsubscribe https://github.com/notifications/unsubscribe-auth/AADVDM5APTUJK5UTQMYQ4WDSOOKJVANCNFSM4TMB253A .

robertsLando commented 3 years ago

Below mongo query is being made, not sure why you would want empty queries ? for each subscription , one query is made.

What do you mean? When a client subscribes to a topic we look for any retained message that should be sent to him.

What is strange is topic: {} in the query you showed here.

@mcollina Why are we escaping and then executing that regex?Here: https://github.com/moscajs/aedes-persistence-mongodb/blob/c8706b5c73aa1f450c51b4e23dd3c92f0d4c8580/persistence.js#L272

Then the query seems empty here https://github.com/moscajs/aedes-persistence-mongodb/blob/c8706b5c73aa1f450c51b4e23dd3c92f0d4c8580/persistence.js#L279

mogupta commented 3 years ago

What do you mean? When a client subscribes to a topic we look for any retained message that should be sent to him.

You are right. What I am asking is why a new connection with clean = true is calling MongoPersistence.prototype.subscriptionsByClient ? if its clean should it query subscriptions collection?

What is strange is topic: {} in the query you showed here.

why would aedes query an empty topic ? MongoPersistence.prototype.createRetainedStreamCombi this function gets the topic as parameter . Then it queries with topic: {} . Passed to mongo topic : '//564fsdf54sd654f6s5d4f' What mongodb interprets topic: {}

From Mongo Debug logs issue initial query [{"find":"tinxy-mqtt-db.retained","limit":0,"skip":0,"query":{"topic":{}},"hint":null,"slaveOk":true,"readPreference":{"mode":"primary"}}]

robertsLando commented 3 years ago

Passed to mongo topic : '//564fsdf54sd654f6s5d4f' What mongodb interprets topic: {}

Hummm that's strange!

What I can tell you is that start topics with a leading / is an anti-pattern in mqtt (it's allowed but it's not good).

Anyway this needs some investigation

What I am asking is why a new connection with clean = true is calling subscriptionsByClient

Are you sure the clean flag set to true on the connect? here we call it only when clean is false.

If the clean flag is false this would explain also the high loads

mogupta commented 3 years ago

Passed to mongo topic : '//564fsdf54sd654f6s5d4f' What mongodb interprets topic: {}

Hummm that's strange!

What I can tell you is that start topics with a leading / is an anti-pattern in mqtt (it's allowed but it's not good).

Anyway this needs some investigation

This seems to be an error while mongodb logs its calls. Its actually returning the correct retained data. not sure why the logs were different.

What I am asking is why a new connection with clean = true is calling subscriptionsByClient

Are you sure the clean flag set to true on the connect? here we call it only when clean is false. If the clean flag is false this would explain also the high loads

I figured. Its actually cleanSubscription calling getSubscription for cleaning. How can we suppress this call ? if devices always connect with clean = true ? Also I noticed outgoingStream is also called. not sure why ? I am not using offline publishng?

robertsLando commented 3 years ago

@mcollina thoughts?

mcollina commented 3 years ago

Unfortunately I do not have time to dig into this. My understanding is that the implementation is mostly correct... as it passes the tests.

I figured. Its actually cleanSubscription calling getSubscription for cleaning. How can we suppress this call ? if devices always connect with clean = true ?

This is the MQTT spec. The clientId might have messages from a previous connection where it connected with clean: false.

Also I noticed outgoingStream is also called. not sure why ? I am not using offline publishng?

Again, this is likely spec behavior. I would recommend to read the source code of aedes and investigate. The fact that you are not using offline publishing does not mean that the query should not be made.

If think you might want to implement a Persistence that does not have certain functionalities.

mogupta commented 3 years ago

I am thinking on those lines only. Thanks for your feedback.

Also Here is another observation after reading the code.

On connect , DelWill , getWill and putWill are always called. When client disconnects getWill and DelWill is called to clear up the wills. This makes sense . But what is happening is whenever ~2000 clients try to connect to the server (on server reboot/ update) mongodb is unable to catch up to the db calls by aedes. setting readPreferece to nearest makes the read calls being read from two 6 core servers . I have a primary and secondary mongodb server setup. This maxes out the CPU to 100% for each server for 5 minutes.

I am using will message to inform the users that the device has timeout / offline. In this specific use case their is no need to clear the wills. The "will" will always be the same. right? I will forrk out the persistance module and go from there. Please share your thoughts if this is the right direction ? Or is there something we can do to reduce persistence calls for the community

mcollina commented 3 years ago

I would recommend to check if this module adds all the needed indexes, i.e. there are no queries that do not use an index.

There are some changes that can be done. The sequence of delWill, getWill and putWill could potentially be implemented with a single DB call in MongoDB. This is likely a big refactor on how Aedes and the persistences work that you might be willing to investigate.


What you are experiencing is dubbed "thundering herd" https://en.wikipedia.org/wiki/Thundering_herd_problem and while this setup suffers this at low values of n, you will experience it anyway on restart.

mogupta commented 3 years ago

The mongo module doesn't add index on will (clientId) and retained (topic) collection. I have fixed that in my code.

Here is what is working out for me. PR Please let me know if you see any downside ?

Mohit

mcollina commented 3 years ago

The mongo module doesn't add index on will (clientId) and retained (topic) collection. I have fixed that in my code.

Would you like to send a PR for those?

mogupta commented 3 years ago

Sure, whenever I can get to it.

mogupta commented 3 years ago

@mcollina @robertsLando So finally I was able to migrate from mongodb persistence to redis. I was blown up by the performance improvement. Earlier even with 12 core CPU it wasn't abale to manage the load for 5000 clients but with redis the CPU shoots up to 100% only for a few seconds.