diff --git a/MqttClient.js b/MqttClient.js index f797859..f7b5e8e 100644 --- a/MqttClient.js +++ b/MqttClient.js @@ -7,9 +7,13 @@ class MqttClient extends EventEmitter { this.options = { ...options, - reconnectPeriod: 30000, - keepalive: 90, + reconnectPeriod: 60_000, //in milliseconds, interval between two reconnections. + connectTimeout: 30_000, //in milliseconds, time to wait before a CONNACK is received + keepalive: 90, //in seconds rejectUnauthorized: true, + resubscribe: false, + clean: true, + protocolVersion: 5, } this.client = null @@ -18,9 +22,9 @@ class MqttClient extends EventEmitter { connect() { this.client = mqtt.connect(`mqtts://${this.options.host}`, this.options) - this.client.on('connect', (connack) => { - //console.log('EVENT connect', connack) - this.emit('connect', connack) + this.client.on('connect', (conAck) => { + //console.log('EVENT connect', conAck) + this.emit('connect', conAck) }) // this.client.on('disconnect', (args) => { @@ -37,11 +41,6 @@ class MqttClient extends EventEmitter { this.emit('close') }) - this.client.on('reconnect', () => { - //console.log('EVENT reconnect') - this.emit('reconnect') - }) - this.client.on('error', (error) => { //console.log('EVENT error', error) this.emit('error', error) diff --git a/connection.js b/connection.js index 050d1bb..d441998 100644 --- a/connection.js +++ b/connection.js @@ -26,7 +26,7 @@ module.exports = function (RED) { RED.auth.needsPermission('vsh-virtual-device.read'), (req, res) => { const connectionNode = RED.nodes.getNode(req.params.nodeId) - res.json({ plan: connectionNode.getPlan() }) + res.json({ plan: connectionNode?.getPlan() ?? 'unknown' }) } ) @@ -81,6 +81,11 @@ module.exports = function (RED) { await this.rater.destroy() if (!this.credentials.thingId) { + this.logger( + 'no thingId present while closing vsh-connection', + null, + 'warn' + ) return done() } @@ -89,7 +94,7 @@ module.exports = function (RED) { try { await this.disconnect() } catch (e) { - console.log('connection.js:this:on:close::', e) + this.logger('disconnect() failed', e, 'error') } this.execCallbackForAll('onDisconnect') @@ -124,7 +129,9 @@ module.exports = function (RED) { if (this.isError) { fill = 'red' - text = this.errorCode + text = `ERROR: ${this.errorCode}. ${ + this.isReconnecting() ? 'Periodically retrying...' : '' + }` } else if (this.isKilled) { fill = 'red' text = this.killedStatusText @@ -234,6 +241,9 @@ module.exports = function (RED) { markShadowAsConnected() { if (!this.isConnected()) { + this.logger( + `skipping markShadowAsConnected() because isConnected() is false` + ) return false } @@ -250,9 +260,9 @@ module.exports = function (RED) { markShadowAsConnectedDebounced = debounce( this.markShadowAsConnected, - 7000, + 5000, { - immediate: true, + immediate: false, //to mitigate race condition with LWT setting device shadow to disconnected } ) @@ -588,7 +598,12 @@ module.exports = function (RED) { return } - console.warn('CONNECTION KILLED! Reason:', reason || 'undefined') + this.logger( + 'CONNECTION KILLED! Reason:', + reason || 'undefined', + null, + 'warn' + ) this.isKilled = true this.killedStatusText = reason ? reason : 'KILLED' this.isInitializing = false @@ -625,6 +640,7 @@ module.exports = function (RED) { default: this.logger( `received service request (${message.operation}) that is not supported by this VSH version. Updating to the latest version might fix this!`, + null, 'warn' ) } @@ -651,7 +667,7 @@ module.exports = function (RED) { // } return response.data } catch (error) { - console.log(error) + this.logger('checkVersion() failed', error, 'error') throw new Error( `HTTP Error Response: ${response.status || 'n/a'} ${ response.statusText || 'n/a' @@ -710,7 +726,8 @@ module.exports = function (RED) { return } } catch (e) { - this.errorCode = 'version check failed' + this.errorCode = + 'version check failed. Ensure internet connectivity and restart the flow' this.isError = true this.refreshChildrenNodeStatus() return this.logger(`version check failed! ${e.message}`, null, 'error') @@ -725,6 +742,9 @@ module.exports = function (RED) { cert: decodeBase64(this.credentials.cert), ca: decodeBase64(this.credentials.caCert), clientId: this.credentials.thingId, + log: (message) => { + this.logger('mqtt.js: ' + message, null, 'debug') + }, will: { topic: `vsh/${this.credentials.thingId}/update`, payload: JSON.stringify({ @@ -739,27 +759,28 @@ module.exports = function (RED) { // register event listeners: this.mqttClient.on('connect', (_conAck) => { - this.logger(`MQTT: connected to ${options.host}:${options.port}`) this.stats.connectionCount++ + this.logger( + `MQTT: connected to ${options.host}:${options.port}, connection #${this.stats.connectionCount}` + ) this.isError = false this.refreshChildrenNodeStatus() - this.markShadowAsConnectedDebounced() - if (!this.isSubscribed) { - const topicsToSubscribe = [ - `$aws/things/${this.credentials.thingId}/shadow/get/accepted`, - `vsh/${this.credentials.thingId}/+/directive`, - `vsh/service`, - `vsh/version/${VSH_VERSION}/+`, - `vsh/${this.credentials.thingId}/service`, - ] - - this.logger('MQTT: subscribe to topics', topicsToSubscribe) - - this.mqttClient.subscribe(topicsToSubscribe).catch((error) => { - console.error('MQTT: subscription failed', error) - }) - } + const topicsToSubscribe = [ + `$aws/things/${this.credentials.thingId}/shadow/get/accepted`, + `vsh/${this.credentials.thingId}/+/directive`, + `vsh/service`, + `vsh/version/${VSH_VERSION}/+`, + `vsh/${this.credentials.thingId}/service`, + ] + + this.logger('MQTT: subscribe to topics', topicsToSubscribe) + + this.mqttClient.subscribe(topicsToSubscribe).catch((error) => { + this.logger('MQTT: subscription failed', error, 'error') + }) + + this.markShadowAsConnectedDebounced() }) this.mqttClient.on('offline', () => { @@ -768,15 +789,13 @@ module.exports = function (RED) { }) this.mqttClient.on('close', () => { + this.logger('MQTT: connection closed') + this.isSubscribed = false this.refreshChildrenNodeStatus() }) - this.mqttClient.on('reconnect', () => { - this.logger('MQTT: reconnecting...') - this.refreshChildrenNodeStatus('Reconnecting...') - }) - this.mqttClient.on('error', (error) => { + this.logger('MQTT: error', error) this.isError = true this.errorCode = error.code this.refreshChildrenNodeStatus() @@ -824,7 +843,7 @@ module.exports = function (RED) { } }) - this.mqttClient.on('subscribed', (topic, messageObj) => { + this.mqttClient.on('subscribed', (_subscriptions) => { this.isSubscribed = true }) @@ -837,6 +856,7 @@ module.exports = function (RED) { async disconnect() { if (this.isDisconnecting) { + this.logger('ignoring disconnect() as already disconnecting') return } diff --git a/package-lock.json b/package-lock.json index 598927e..1633dcf 100644 --- a/package-lock.json +++ b/package-lock.json @@ -13,10 +13,10 @@ "bottleneck": "^2.19.5", "color-convert": "^2.0.1", "dayjs": "^1.11.5", - "debounce": "^1.2.0", + "debounce": "^2.0.0", "deep-eql": "^4.1.0", "deepmerge": "^4.2.2", - "mqtt": "^5.3.4", + "mqtt": "^5.3.5", "semver": "^7.3.7" }, "engines": { @@ -81,20 +81,15 @@ "integrity": "sha512-Oei9OH4tRh0YqU3GxhX79dM/mwVgvbZJaSNaRk+bshkj0S5cfHcgYakreBjrHwatXKbz+IoIdYLxrKim2MjW0Q==" }, "node_modules/axios": { - "version": "1.6.5", - "resolved": "https://registry.npmjs.org/axios/-/axios-1.6.5.tgz", - "integrity": "sha512-Ii012v05KEVuUoFWmMW/UQv9aRIc3ZwkWDcM+h5Il8izZCtRVpDUfwpoFf7eOtajT3QiGR4yDUx7lPqHJULgbg==", + "version": "1.6.7", + "resolved": "https://registry.npmjs.org/axios/-/axios-1.6.7.tgz", + "integrity": "sha512-/hDJGff6/c7u0hDkvkGxR/oy6CbCs8ziCsC7SqmhjfozqiJGc8Z11wrv9z9lYfY4K8l+H9TpjcMDX0xOZmx+RA==", "dependencies": { "follow-redirects": "^1.15.4", "form-data": "^4.0.0", "proxy-from-env": "^1.1.0" } }, - "node_modules/balanced-match": { - "version": "1.0.2", - "resolved": "https://registry.npmjs.org/balanced-match/-/balanced-match-1.0.2.tgz", - "integrity": "sha512-3oSeUO0TMV67hN1AmbXsK4yaqU7tjiHlbxRDZOpH0KW9+CeX4bRAaX0Anxt0tx2MrpRpWwQaPwIlISEJhYU5Pw==" - }, "node_modules/base64-js": { "version": "1.5.1", "resolved": "https://registry.npmjs.org/base64-js/-/base64-js-1.5.1.tgz", @@ -144,14 +139,6 @@ "resolved": "https://registry.npmjs.org/bottleneck/-/bottleneck-2.19.5.tgz", "integrity": "sha512-VHiNCbI1lKdl44tGrhNfU3lup0Tj/ZBMJB5/2ZbNXRCPuRCO7ed2mgcK4r17y+KB2EfuYuRaVlwNbAeaWGSpbw==" }, - "node_modules/brace-expansion": { - "version": "2.0.1", - "resolved": "https://registry.npmjs.org/brace-expansion/-/brace-expansion-2.0.1.tgz", - "integrity": "sha512-XnAIvQ8eM+kC6aULx6wuQiwVsnzsi9d3WxzV3FpWTGA19F621kwdbsAcFKXgKUHZWsy+mY6iL1sHTxWEFCytDA==", - "dependencies": { - "balanced-match": "^1.0.0" - } - }, "node_modules/buffer": { "version": "6.0.3", "resolved": "https://registry.npmjs.org/buffer/-/buffer-6.0.3.tgz", @@ -232,9 +219,15 @@ "integrity": "sha512-vjAczensTgRcqDERK0SR2XMwsF/tSvnvlv6VcF2GIhg6Sx4yOIt/irsr1RDJsKiIyBzJDpCoXiWWq28MqH2cnQ==" }, "node_modules/debounce": { - "version": "1.2.1", - "resolved": "https://registry.npmjs.org/debounce/-/debounce-1.2.1.tgz", - "integrity": "sha512-XRRe6Glud4rd/ZGQfiV1ruXSfbvfJedlV9Y6zOlP+2K04vBYiJEte6stfFkCP03aMnY5tsipamumUjL14fofug==" + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/debounce/-/debounce-2.0.0.tgz", + "integrity": "sha512-xRetU6gL1VJbs85Mc4FoEGSjQxzpdxRyFhe3lmWFyy2EzydIcD4xzUvRJMD+NPDfMwKNhxa3PvsIOU32luIWeA==", + "engines": { + "node": ">=18" + }, + "funding": { + "url": "https://github.com/sponsors/sindresorhus" + } }, "node_modules/debug": { "version": "4.3.4", @@ -339,37 +332,10 @@ "node": ">= 6" } }, - "node_modules/fs.realpath": { - "version": "1.0.0", - "resolved": "https://registry.npmjs.org/fs.realpath/-/fs.realpath-1.0.0.tgz", - "integrity": "sha512-OO0pH2lK6a0hZnAdau5ItzHPI6pUlvI7jMVnxUQRtw4owF2wk8lOSabtGDCTP4Ggrg2MbGnWO9X8K1t4+fGMDw==" - }, - "node_modules/glob": { - "version": "8.1.0", - "resolved": "https://registry.npmjs.org/glob/-/glob-8.1.0.tgz", - "integrity": "sha512-r8hpEjiQEYlF2QU0df3dS+nxxSIreXQS1qRhMJM0Q5NDdR386C7jb7Hwwod8Fgiuex+k0GFjgft18yvxm5XoCQ==", - "dependencies": { - "fs.realpath": "^1.0.0", - "inflight": "^1.0.4", - "inherits": "2", - "minimatch": "^5.0.1", - "once": "^1.3.0" - }, - "engines": { - "node": ">=12" - }, - "funding": { - "url": "https://github.com/sponsors/isaacs" - } - }, "node_modules/help-me": { - "version": "4.2.0", - "resolved": "https://registry.npmjs.org/help-me/-/help-me-4.2.0.tgz", - "integrity": "sha512-TAOnTB8Tz5Dw8penUuzHVrKNKlCIbwwbHnXraNJxPwf8LRtE2HlM84RYuezMFcwOJmoYOCWVDyJ8TQGxn9PgxA==", - "dependencies": { - "glob": "^8.0.0", - "readable-stream": "^3.6.0" - } + "version": "5.0.0", + "resolved": "https://registry.npmjs.org/help-me/-/help-me-5.0.0.tgz", + "integrity": "sha512-7xgomUX6ADmcYzFik0HzAxh/73YlKR9bmFzf51CZwR+b6YtzU2m0u49hQCqV6SvlqIqsaxovfwdvbnsw3b/zpg==" }, "node_modules/ieee754": { "version": "1.2.1", @@ -390,15 +356,6 @@ } ] }, - "node_modules/inflight": { - "version": "1.0.6", - "resolved": "https://registry.npmjs.org/inflight/-/inflight-1.0.6.tgz", - "integrity": "sha512-k92I/b08q4wvFscXCLvqfsHCrjrF7yiXsQuIVvVE7N82W3+aqpzuUdBbfhWcy/FZR3/4IgflMgKLOsvPDrGCJA==", - "dependencies": { - "once": "^1.3.0", - "wrappy": "1" - } - }, "node_modules/inherits": { "version": "2.0.4", "resolved": "https://registry.npmjs.org/inherits/-/inherits-2.0.4.tgz", @@ -443,17 +400,6 @@ "node": ">= 0.6" } }, - "node_modules/minimatch": { - "version": "5.1.6", - "resolved": "https://registry.npmjs.org/minimatch/-/minimatch-5.1.6.tgz", - "integrity": "sha512-lKwV/1brpG6mBUFHtb7NUmtABCb2WZZmm2wNiOA5hAb8VdCS4B3dtMWyvcoViccwAW/COERjXLt0zP1zXUN26g==", - "dependencies": { - "brace-expansion": "^2.0.1" - }, - "engines": { - "node": ">=10" - } - }, "node_modules/minimist": { "version": "1.2.8", "resolved": "https://registry.npmjs.org/minimist/-/minimist-1.2.8.tgz", @@ -463,16 +409,16 @@ } }, "node_modules/mqtt": { - "version": "5.3.4", - "resolved": "https://registry.npmjs.org/mqtt/-/mqtt-5.3.4.tgz", - "integrity": "sha512-nyhr2bnFtyiv68jV3yfR6eQtGcGs/jr2l3ETKXYc0amttsasXa1KgvETHRNRjfeDt/yc68IqoEjFzKkHpoQUPQ==", + "version": "5.3.5", + "resolved": "https://registry.npmjs.org/mqtt/-/mqtt-5.3.5.tgz", + "integrity": "sha512-xd7qt/LEM721U6yHQcqjlaAKXL1Fsqf/MXq6C2WPi/6OXK2jdSzL1eZ7ZUgjea7IY2yFLRWD5LNdT1mL0arPoA==", "dependencies": { "@types/readable-stream": "^4.0.5", "@types/ws": "^8.5.9", "commist": "^3.2.0", "concat-stream": "^2.0.0", "debug": "^4.3.4", - "help-me": "^4.2.0", + "help-me": "^5.0.0", "lru-cache": "^10.0.1", "minimist": "^1.2.8", "mqtt": "^5.2.0", @@ -541,14 +487,6 @@ "js-sdsl": "4.3.0" } }, - "node_modules/once": { - "version": "1.4.0", - "resolved": "https://registry.npmjs.org/once/-/once-1.4.0.tgz", - "integrity": "sha512-lNaJgI+2Q5URQBkccEKHTQOPaXdUxnZZElQTZY0MFUAuaEqe1E+Nyvgdz/aIyNi6Z9MzO5dv1H8n58/GELp3+w==", - "dependencies": { - "wrappy": "1" - } - }, "node_modules/process": { "version": "0.11.10", "resolved": "https://registry.npmjs.org/process/-/process-0.11.10.tgz", @@ -615,9 +553,9 @@ ] }, "node_modules/semver": { - "version": "7.5.4", - "resolved": "https://registry.npmjs.org/semver/-/semver-7.5.4.tgz", - "integrity": "sha512-1bCSESV6Pv+i21Hvpxp3Dx+pSD8lIPt8uVjRrxAUt/nbswYc+tK6Y2btiULjd4+fnq15PX+nqQDC7Oft7WkwcA==", + "version": "7.6.0", + "resolved": "https://registry.npmjs.org/semver/-/semver-7.6.0.tgz", + "integrity": "sha512-EnwXhrlwXMk9gKu5/flx5sv/an57AkRplG3hTK68W7FRDN+k+OWBj65M7719OkA82XLBxrcX0KSHj+X5COhOVg==", "dependencies": { "lru-cache": "^6.0.0" }, @@ -703,11 +641,6 @@ "tslib": "^2.6.2" } }, - "node_modules/wrappy": { - "version": "1.0.2", - "resolved": "https://registry.npmjs.org/wrappy/-/wrappy-1.0.2.tgz", - "integrity": "sha512-l4Sp/DRseor9wL6EvV2+TuQn63dMkPjZ/sp9XkghTEbV9KlPS1xUsZ3u7/IQO4wxtcFB4bgpQPRcR3QCvezPcQ==" - }, "node_modules/ws": { "version": "8.16.0", "resolved": "https://registry.npmjs.org/ws/-/ws-8.16.0.tgz", diff --git a/package.json b/package.json index 4e6b314..50ec142 100644 --- a/package.json +++ b/package.json @@ -45,10 +45,10 @@ "bottleneck": "^2.19.5", "color-convert": "^2.0.1", "dayjs": "^1.11.5", - "debounce": "^1.2.0", + "debounce": "^2.0.0", "deep-eql": "^4.1.0", "deepmerge": "^4.2.2", - "mqtt": "^5.3.4", + "mqtt": "^5.3.5", "semver": "^7.3.7" }, "engines": {