moscajs / mosca

MQTT broker as a module
mosca.io
3.2k stars 508 forks source link

Duplication of some forwardOfflineMessages? #271

Closed behrad closed 9 years ago

behrad commented 9 years ago

I see my client occasionally receives an offline multiple times (within 60-70 milliseconds), it seems mosca is forwarding a message twice!? I can't find a clue looking at the code @mcollina

mcollina commented 9 years ago

An offline message is resent if Mosca did non receive a PUBACK. Can you check your client is sending it?

behrad commented 9 years ago

yes it is sending, and my onDelivered event which is called on receiving puback is called 2, 3 times within 120 millis. (it only happens for clients which are on Mobile Data (slow) networks) Can you link me to the resending code to see if the interval is tunable?

mcollina commented 9 years ago

It's resent only because Mosca see the device as disconnected and reconnect it. There is no automatic retry (there was in an old version).

What's the keepalive of the device?

behrad commented 9 years ago

keepAlive = 120s reconnectDelay = 10s mobile DATA network is loosy.

mcollina commented 9 years ago

check in the logs that if it sees the device as disconnected.

I found out that on mobile networks the best keepalive is 30 minutes.

behrad commented 9 years ago

even with keepalive 15mins, I saw 6x message forward (6x pubacks) for a single offline message after reconnect. (time between disconnect/reconnect was about 2hours)

mcollina commented 9 years ago

There is no code that does retransmissions. Only after a connect the offline queue is emptied.

What Mosca backend are you using? Which client? Il giorno mar 9 giu 2015 alle 18:05 Behrad notifications@github.com ha scritto:

even with keepalive 15mins, I saw 6x message forward (6x pubacks) for a single offline message after reconnect. (time between disconnect/reconnect was about 2hours)

— Reply to this email directly or view it on GitHub https://github.com/mcollina/mosca/issues/271#issuecomment-110416484.

behrad commented 9 years ago

I see @mcollina , I just can't interpret what that is happening... mosca backed by Redis client is https://github.com/fusesource/mqtt-client

behrad commented 9 years ago

may it be the client sending multiple pubacks to a single message packet forwarded by Mosca !?

mcollina commented 9 years ago

Do you have any way to check if that's the case? Turn mosca logs to debug level, and maybe forward it to me (tell me the clientId of your client!) Il giorno mar 9 giu 2015 alle 18:40 Behrad notifications@github.com ha scritto:

may it be the client sending multiple pubacks to a single message packet forwarded by Mosca !?

— Reply to this email directly or view it on GitHub https://github.com/mcollina/mosca/issues/271#issuecomment-110426968.

behrad commented 9 years ago
2015-06-10T05:29:01.570Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:01.570Z","v":0}
2015-06-10T05:29:01.571Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"topic":"app/adp-nms-push/user/989395336383/default","qos":1,"msg":"restoring subscription","time":"2015-06-10T05:29:01.571Z","v":0}
2015-06-10T05:29:01.572Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":30,"topic":"app/adp-nms-push/user/989395336383/default","qos":1,"msg":"subscribed to topic","time":"2015-06-10T05:29:01.572Z","v":0}
2015-06-10T05:29:01.573Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":30,"msg":"client connected","time":"2015-06-10T05:29:01.572Z","v":0}
2015-06-10T05:29:01.575Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"level":20,"packet":{"topic":"$SYS/behrad/new/clients"},"msg":"published packet","time":"2015-06-10T05:29:01.575Z","v":0}
2015-06-10T05:29:01.576Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":"NySRzjxI","topic":"app/adp-nms-push/user/989395336383/default","qos":1},"msg":"Forwarding offline packet","time":"2015-06-10T05:29:01.576Z","v":0}
2015-06-10T05:29:01.577Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":"NySRzjxI","topic":"app/adp-nms-push/user/989395336383/default","qos":1},"msg":"Forwarding offline packet","time":"2015-06-10T05:29:01.577Z","v":0}
2015-06-10T05:29:01.577Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":"NySRzjxI","topic":"app/adp-nms-push/user/989395336383/default","qos":1},"msg":"Forwarding offline packet","time":"2015-06-10T05:29:01.577Z","v":0}
2015-06-10T05:29:01.578Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":"NySRzjxI","topic":"app/adp-nms-push/user/989395336383/default","qos":1},"msg":"Forwarding offline packet","time":"2015-06-10T05:29:01.578Z","v":0}
2015-06-10T05:29:01.578Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":"NySRzjxI","topic":"app/adp-nms-push/user/989395336383/default","qos":1},"msg":"Forwarding offline packet","time":"2015-06-10T05:29:01.578Z","v":0}
2015-06-10T05:29:01.578Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":"NySRzjxI","topic":"app/adp-nms-push/user/989395336383/default","qos":1},"msg":"Forwarding offline packet","time":"2015-06-10T05:29:01.578Z","v":0}
2015-06-10T05:29:01.579Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":"NySRzjxI","topic":"app/adp-nms-push/user/989395336383/default","qos":1},"msg":"Forwarding offline packet","time":"2015-06-10T05:29:01.578Z","v":0}
2015-06-10T05:29:01.579Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":"NySRzjxI","topic":"app/adp-nms-push/user/989395336383/default","qos":1},"msg":"Forwarding offline packet","time":"2015-06-10T05:29:01.579Z","v":0}
2015-06-10T05:29:01.579Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":"NySRzjxI","topic":"app/adp-nms-push/user/989395336383/default","qos":1},"msg":"Forwarding offline packet","time":"2015-06-10T05:29:01.579Z","v":0}
2015-06-10T05:29:02.480Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:02.480Z","v":0}
2015-06-10T05:29:02.480Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":1,"qos":1,"subscriptions":[{"topic":"app/adp-nms-push/user/989395336383/default","qos":1}]},"msg":"subscribe received","time":"2015-06-10T05:29:02.480Z","v":0}
2015-06-10T05:29:02.481Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:02.481Z","v":0}
2015-06-10T05:29:02.481Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":1},"msg":"puback","time":"2015-06-10T05:29:02.481Z","v":0}
2015-06-10T05:29:02.482Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler onDelivered message 1433908148333 to adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0
2015-06-10T05:29:02.484Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:02.484Z","v":0}
2015-06-10T05:29:02.484Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":2},"msg":"puback","time":"2015-06-10T05:29:02.484Z","v":0}
2015-06-10T05:29:02.484Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler onDelivered message 1433908148333 to adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0
2015-06-10T05:29:02.486Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:02.486Z","v":0}
2015-06-10T05:29:02.486Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":3},"msg":"puback","time":"2015-06-10T05:29:02.486Z","v":0}
2015-06-10T05:29:02.486Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler onDelivered message 1433908148333 to adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0
2015-06-10T05:29:02.487Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:02.487Z","v":0}
2015-06-10T05:29:02.488Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":4},"msg":"puback","time":"2015-06-10T05:29:02.487Z","v":0}
2015-06-10T05:29:02.488Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler onDelivered message 1433908148333 to adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0
2015-06-10T05:29:02.490Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:02.490Z","v":0}
2015-06-10T05:29:02.490Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":5},"msg":"puback","time":"2015-06-10T05:29:02.490Z","v":0}
2015-06-10T05:29:02.490Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler onDelivered message 1433908148333 to adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0
2015-06-10T05:29:02.493Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:02.493Z","v":0}
2015-06-10T05:29:02.493Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":6},"msg":"puback","time":"2015-06-10T05:29:02.493Z","v":0}
2015-06-10T05:29:02.493Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler onDelivered message 1433908148333 to adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0
2015-06-10T05:29:02.496Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:02.495Z","v":0}
2015-06-10T05:29:02.496Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":7},"msg":"puback","time":"2015-06-10T05:29:02.496Z","v":0}
2015-06-10T05:29:02.496Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler onDelivered message 1433908148333 to adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0
2015-06-10T05:29:02.498Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:02.498Z","v":0}
2015-06-10T05:29:02.498Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":8},"msg":"puback","time":"2015-06-10T05:29:02.498Z","v":0}
2015-06-10T05:29:02.499Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler onDelivered message 1433908148333 to adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0
2015-06-10T05:29:02.500Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"timeout":1350000,"msg":"setting keepalive timeout","time":"2015-06-10T05:29:02.500Z","v":0}
2015-06-10T05:29:02.501Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":9},"msg":"puback","time":"2015-06-10T05:29:02.500Z","v":0}
2015-06-10T05:29:02.501Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler onDelivered message 1433908148333 to adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0
2015-06-10T05:29:02.504Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":1},"msg":"cleaned offline packet","time":"2015-06-10T05:29:02.504Z","v":0}
2015-06-10T05:29:02.504Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":2},"msg":"cleaned offline packet","time":"2015-06-10T05:29:02.504Z","v":0}
2015-06-10T05:29:02.505Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":3},"msg":"cleaned offline packet","time":"2015-06-10T05:29:02.504Z","v":0}
2015-06-10T05:29:02.505Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":4},"msg":"cleaned offline packet","time":"2015-06-10T05:29:02.505Z","v":0}
2015-06-10T05:29:02.505Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":5},"msg":"cleaned offline packet","time":"2015-06-10T05:29:02.505Z","v":0}
2015-06-10T05:29:02.505Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":6},"msg":"cleaned offline packet","time":"2015-06-10T05:29:02.505Z","v":0}
2015-06-10T05:29:02.505Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":7},"msg":"cleaned offline packet","time":"2015-06-10T05:29:02.505Z","v":0}
2015-06-10T05:29:02.505Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":8},"msg":"cleaned offline packet","time":"2015-06-10T05:29:02.505Z","v":0}
2015-06-10T05:29:02.505Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"client":"adp-nms-push/989395336383/557713ae418fb8bc4c9e6ad0","level":20,"packet":{"messageId":9},"msg":"cleaned offline packet","time":"2015-06-10T05:29:02.505Z","v":0}
2015-06-10T05:29:02.508Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler installation 557713ae418fb8bc4c9e6ad0 badge -1
2015-06-10T05:29:02.512Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler installation 557713ae418fb8bc4c9e6ad0 badge -1
2015-06-10T05:29:02.513Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler installation 557713ae418fb8bc4c9e6ad0 badge -1
2015-06-10T05:29:02.515Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler installation 557713ae418fb8bc4c9e6ad0 badge -1
2015-06-10T05:29:02.524Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler installation 557713ae418fb8bc4c9e6ad0 badge -1
2015-06-10T05:29:02.525Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler installation 557713ae418fb8bc4c9e6ad0 badge -1
2015-06-10T05:29:02.527Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler installation 557713ae418fb8bc4c9e6ad0 badge -1
2015-06-10T05:29:02.528Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler installation 557713ae418fb8bc4c9e6ad0 badge -1
2015-06-10T05:29:02.532Z pid:19650 worker:3 Wed, 10 Jun 2015 05:29:02 GMT adp-push:deliveryHandler installation 557713ae418fb8bc4c9e6ad0 badge -1
2015-06-10T05:29:02.537Z pid:19650 worker:3 {"name":"mosca","hostname":"behrad","pid":19650,"level":20,"packet":{"topic":"$SYS/behrad/new/subscribes"},"msg":"published packet","time":"2015-06-10T05:29:02.534Z","v":0}
behrad commented 9 years ago

it shows that a singel messageId is forwarded multiple times by RedisPersistence.streamOfflinePackets

mcollina commented 9 years ago

Are you sure it's the same problem? It doesn't seems related to timing at all and retransmission. You are getting multiple times the same message, but in the same timeframe (at connection!).

mcollina commented 9 years ago

Can you please add the logs where that message is stored? Probably something bad happens there, as I see no flaw in the code. Here is the relevant logic: https://github.com/mcollina/mosca/blob/master/lib/persistence/redis.js#L333-L396

Which version of Redis are you using?

behrad commented 9 years ago

I see the same behavior with our ObjectiveC mqtt client also, I am not sure if it depends on node.js cluster module! (Mosca is ran on clustered processes) redis is 2.8.4 on localhost

Seeing this more frequently recently. Hopefully is producing many times this week (I can't find why but seeing this recently, no changes in my code which may concern to this... but it should be due to our overall configuration/setup which produces this recently) I will try to check redis keys when storing messages... that should explain why mosca is forwarding multiple times a single packet to a single client id.

a question: can multiple subscriptions of the same clientId to a single topic produce this? taking that our clients are re-subscribing on reconnects accidentally.

mcollina commented 9 years ago

can you please check if it is related to the cluster?

I don't think this is relevant to multiple subscriptions: see https://github.com/mcollina/mosca/blob/master/lib/persistence/redis.js#L246-L264. Also the redis key where subscriptions are stored is showed there.

behrad commented 9 years ago

good suspect! thank you @mcollina I will test both cluster, and multiple subscriptions and on publish snopshot, and let you informed in a few hours

behrad commented 9 years ago

it is a storePacket issue when using cluster, all other processes are adding duplicate submatchers when storeSubscriptions is called for a client: https://github.com/mcollina/mosca/blob/master/lib/persistence/redis.js#L107

for each packet then each process matches multiple items for a client https://github.com/mcollina/mosca/blob/master/lib/persistence/redis.js#L327 since storing a packet in the client listKey multiple times adding a guard like https://github.com/mcollina/mosca/blob/master/lib/persistence/redis.js#L261 fixes this issue.

If you think this is a valid workaround, I can create a PR.

mcollina commented 9 years ago

All clustered instances of Mosca needs to have different 'ids': https://github.com/mcollina/mosca/blob/master/lib/server.js#L154. Probably in your case they all have the same, and this bad behavior happen.

Anyway, send a PR that fixes it :D.

behrad commented 9 years ago

hmmm! remember days I was using process-id in my mosca instance ids, and the issue was not happening :)) this was the change that made the problem pop out hopefully.

I changed mosca id to my machine unique name so that I have a unified statsd collector in my monitoring visualizations.

Is it recommended to use separate per process mosca ids?

behrad commented 9 years ago

https://github.com/mcollina/mosca/pull/273

mcollina commented 9 years ago

You have to use separate, per-process mosca ids. It might be worth it guard the system against this, as bad things happens when uniqueness is not respected. That id is used internally for some things, not just for logging.

I'm more inclined in guarding against id collision (crash if there is an id collision), than supporting this use case, as it might lead to other issues I cannot foresee now.

This comment is definitely wrong: https://github.com/mcollina/mosca/blob/master/lib/server.js#L153

behrad commented 9 years ago

then I should roll back my commit and use separate ids per process for now !?

mcollina commented 9 years ago

That should be the best approach, yes.

This needs to be handled anyway, we might want to have something for the logs, and a non-overridable, per-process identifier. What do you think?

behrad commented 9 years ago

If you mean the broker id should be set internally by the broker, I agree. currently I'm setting [require('os').hostname(),process.pid].join('-')

behrad commented 9 years ago

@mcollina I'm confirming that rolling back my change, and using different broker ids is regenerating the issue! the duplicate client id addition to submatcher is because of redis pub/sub and no broker id is envolved there. My change fixes this issue and seems non vulnerable.

behrad commented 9 years ago

what happens to this @mcollina ? I think we can merge this in