mosca collapses when directly closing browser which runs mqtt client

[simonxuhao]

Steps to reproduce the bug:

1. Install mosca
   npm install mosca bunyan

2. start mosca
   mosca -v --http-port 8888 | bunyan

3. open mqtt.io in a browser window, set last will topic to 'abc123' and last will message, connect to the broker and subscribe to topic 'abc123', publish a message

4. directly shutdown the browser, mosca broker goes crazy:

[2014-03-04T07:30:00.896Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.898Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
[2014-03-04T07:30:00.899Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.899Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
[2014-03-04T07:30:00.900Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.900Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
[2014-03-04T07:30:00.903Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.903Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
[2014-03-04T07:30:00.905Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.905Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
[2014-03-04T07:30:00.906Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.906Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
[2014-03-04T07:30:00.907Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.907Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
[2014-03-04T07:30:00.908Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.908Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
[2014-03-04T07:30:00.909Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.909Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
[2014-03-04T07:30:00.910Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.911Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
[2014-03-04T07:30:00.911Z] WARN: mosca/4232 on Arch: Not connected (client=kRZB3Q0CGByl5DO2MG3Vc)
[2014-03-04T07:30:00.911Z] INFO: mosca/4232 on Arch: delivering last will (client=kRZB3Q0CGByl5DO2MG3Vc, willTopic=abc123)
....
....

and quits

The issue is 100% reproducible on Chrome and IE11. Didn't try Firefox.

bunyan@0.22.1 ../node_modules/bunyan
├── mv@0.0.5
└── dtrace-provider@0.2.8

mosca@0.17.4 ../node_modules/mosca
├── extend@1.1.3
├── moving-average@0.0.4
├── debug@0.7.4
├── pre-commit@0.0.4
├── lru-cache@2.5.0
├── node-uuid@1.4.1
├── async@0.2.10
├── commander@1.1.1 (keypress@0.1.0)
├── minimatch@0.2.14 (sigmund@1.0.0)
├── qlobber@0.3.8
├── level-ttl@0.4.1 (after@0.8.1, xtend@2.1.2)
├── json-buffer@2.0.7 (bops@0.0.6)
├── redis@0.8.6
├── express@3.3.8 (methods@0.0.1, cookie-signature@1.0.1, range-parser@0.0.4, fresh@0.2.0, buffer-crc32@0.2.1, cookie@0.1.0, mkdirp@0.3.5, commander@1.2.0, send@0.1.4)
├── memdown@0.5.1 (bops@0.1.1, abstract-leveldown@0.11.3)
├── level-sublevel@5.1.1 (string-range@1.2.2, level-hooks@4.4.5, level-fix-range@2.0.0, xtend@2.0.6)
├── mqtt@0.3.7 (bops@0.1.1, readable-stream@1.0.26-2)
├── ascoltatori@0.12.2 (eventemitter2@0.4.13)
├── levelup@0.18.2 (concat-stream@0.1.1, prr@0.0.0, errno@0.1.0, xtend@2.1.2, semver@2.2.1, readable-stream@1.0.26-2, deferred-leveldown@0.1.0, bops@0.1.1)
├── connect@2.8.8 (methods@0.0.1, uid2@0.0.2, cookie-signature@1.0.1, pause@0.0.1, fresh@0.2.0, qs@0.6.5, bytes@0.2.0, buffer-crc32@0.2.1, cookie@0.1.0, send@0.1.4, formidable@1.0.14)
├── amqp@0.1.8 (longjohn@0.2.2, lodash@1.3.1)
├── brfs@0.0.8 (through@2.2.7, falafel@0.1.6, escodegen@0.0.17)
├── moment@2.5.1
├── mows@0.0.4 (websocket-stream@0.3.3, ws@0.4.31)
├── mongodb@1.3.23 (kerberos@0.0.3, bson@0.2.5)
├── browserify-middleware@2.1.0 (ms@0.6.2, callsite@1.0.0, mold-source-map@0.3.0, uglify-js@2.4.12, browserify@3.2.2)
└── leveldown@0.10.2 (bindings@1.1.1, nan@0.6.0)

[mcollina]

This is a very bad bug. I never tested putting the will on the same topic of the device is subscribed.

I'll have a look at it. However it is very important the last part of the stacktrace before it quits. Can you add it?

[mcollina]

Confirmed, there is an infinite loop when delivering the last will.
I'm not sure why this is triggered only by the MQTT over Websocket thing.

[mcollina]

Can you please try https://github.com/mcollina/mosca/compare/no-will-infinite-loop and see if it works for you? It worked for me.

[simonxuhao]

Tested on mqtt.io with all combinations of Last-Will QoS Last-Will Retain, it worked fine.

[2014-03-05T02:11:13.766Z] INFO: mosca/356 on Arch: delivering last will (client=JLq2lQlZHdOrEfsmLNSxE, willTopic=abc123)
[2014-03-05T02:11:13.767Z] INFO: mosca/356 on Arch: unsubscribed (client=JLq2lQlZHdOrEfsmLNSxE, topic=abc123)
[2014-03-05T02:11:13.772Z] INFO: mosca/356 on Arch: closed (client=JLq2lQlZHdOrEfsmLNSxE)

[mcollina]

Released as 0.17.5.

Thanks!