Mqtt connection close | close event triggered

[dasaripravin-developer]

Hello All,

I facing the mqtt connection issue. Initially, the connection was established but after some time the close event triggered and didn't receive any parameters. Therefore we are unable to troubleshoot the issue.

Please anyone assist me in resolving this issue.

Thank you in advance.

[jsiegenthaler]

I think it would help if you provide more details. How much time elapsed before the close event was triggered: Seconds? Minutes? Hours? Days? Months?

[robertsLando]

If running on node please add the env var DEBUG=mqttjs* and paste the logs here

[dasaripravin-developer]

I think it would help if you provide more details. How much time elapsed before the close event was triggered: Seconds? Minutes? Hours? Days? Months?

Time is not fixed, It behaves randomly, and after a few seconds reconnect with mqtt broker.
Find the below options object which i provided while connecting with broker.

{ rejectUnauthorized: false, clean: false, clientId: 'CLIENT-1785965412365, reconnectPeriod: 5000, connectTimeout: (30 * 1000) * 4, cleanSession: false, username: 'ab.bb@abc.com', password: 'eyJhbGciOiJIUzI1NiJ9.eyJqdGkiOiJiYjJkZjE3NS00NDM3LTQ4ZWQtYTRlZC1mODg1ZWMyODRjNWUiLCJpYXQiOjE2OTM1NjgxNTQsInN1YiI6Im1xdHRDbGllbnRBdXRoZW50aWNhdGlvblRva2VuIiwiaXNzIjoiTVFUVF9BVVRIX0NMWl9DT00iLCJ1c2VySWQiOiJub2RlLm1xdHRAY2xvdXplci5jb20iLCJleHAiOjE3MjUxOTA1NTR9.hjWDWiTP5LSgiwwTFQzQ8ZA5zDq01qmUTQLjJItokEwkl2r29j', resubscribe: true }

Let me know if you need anything else.

[robertsLando]

If running on node please add the env var DEBUG=mqttjs* and paste the logs here

I need this, when the error happens. Also please post the version you are using and if you are not using latest upgrade to latest and retry

[dasaripravin-developer]

If running on node please add the env var DEBUG=mqttjs* and paste the logs here

I need this, when the error happens. Also please post the version you are using and if you are not using latest upgrade to latest and retry

Hello @robertsLando

Please find the below debug logs.

In etMqttServer : mqttConnect : test - connect : mqtt client successfully connected with broker 
IN CONNECT ======>[object Object]
  mqttjs:client _checkPing :: checking ping... +1m
  mqttjs:client _checkPing :: ping response received. Clearing flag and sending `pingreq` +1ms
  mqttjs:client _sendPacket :: (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240) ::  start +0ms
  mqttjs:client sendPacket :: packet: { cmd: 'pingreq' } +1ms
  mqttjs:client sendPacket :: emitting `packetsend` +1ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingreq"}
  mqttjs:client sendPacket :: writing to stream +0ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client sendPacket :: invoking cb +0ms
  mqttjs:client nop :: undefined +1ms
  mqttjs:client writable stream :: parsing buffer +33ms
  mqttjs:client parser :: on packet push to packets array. +0ms
  mqttjs:client work :: getting next packet in queue +1ms
  mqttjs:client work :: packet pulled from queue +0ms
  mqttjs:client _handlePacket :: emitting packetreceive +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingresp","retain":false,"qos":0,"dup":false,"length":0,"topic":null,"payload":null}
  mqttjs:client _checkPing :: checking ping... +60s
  mqttjs:client _checkPing :: ping response received. Clearing flag and sending `pingreq` +1ms
  mqttjs:client _sendPacket :: (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240) ::  start +0ms
  mqttjs:client sendPacket :: packet: { cmd: 'pingreq' } +1ms
  mqttjs:client sendPacket :: emitting `packetsend` +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingreq"}
  mqttjs:client sendPacket :: writing to stream +1ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client sendPacket :: invoking cb +0ms
  mqttjs:client nop :: undefined +0ms
  mqttjs:client writable stream :: parsing buffer +15ms
  mqttjs:client parser :: on packet push to packets array. +1ms
  mqttjs:client work :: getting next packet in queue +0ms
  mqttjs:client work :: packet pulled from queue +0ms
  mqttjs:client _handlePacket :: emitting packetreceive +1ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingresp","retain":false,"qos":0,"dup":false,"length":0,"topic":null,"payload":null}
  mqttjs:client _checkPing :: checking ping... +1m
  mqttjs:client _checkPing :: ping response received. Clearing flag and sending `pingreq` +0ms
  mqttjs:client _sendPacket :: (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240) ::  start +0ms
  mqttjs:client sendPacket :: packet: { cmd: 'pingreq' } +0ms
  mqttjs:client sendPacket :: emitting `packetsend` +1ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingreq"}
  mqttjs:client sendPacket :: writing to stream +0ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client sendPacket :: invoking cb +0ms
  mqttjs:client nop :: undefined +0ms
  mqttjs:client writable stream :: parsing buffer +17ms
  mqttjs:client parser :: on packet push to packets array. +1ms
  mqttjs:client work :: getting next packet in queue +0ms
  mqttjs:client work :: packet pulled from queue +1ms
  mqttjs:client _handlePacket :: emitting packetreceive +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingresp","retain":false,"qos":0,"dup":false,"length":0,"topic":null,"payload":null}
  mqttjs:client _checkPing :: checking ping... +1m
  mqttjs:client _checkPing :: ping response received. Clearing flag and sending `pingreq` +0ms
  mqttjs:client _sendPacket :: (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240) ::  start +1ms
  mqttjs:client sendPacket :: packet: { cmd: 'pingreq' } +0ms
  mqttjs:client sendPacket :: emitting `packetsend` +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingreq"}
  mqttjs:client sendPacket :: writing to stream +1ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client sendPacket :: invoking cb +0ms
  mqttjs:client nop :: undefined +0ms
  mqttjs:client writable stream :: parsing buffer +23ms
  mqttjs:client parser :: on packet push to packets array. +1ms
  mqttjs:client work :: getting next packet in queue +0ms
  mqttjs:client work :: packet pulled from queue +0ms
  mqttjs:client _handlePacket :: emitting packetreceive +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingresp","retain":false,"qos":0,"dup":false,"length":0,"topic":null,"payload":null}
  mqttjs:client _checkPing :: checking ping... +1m
  mqttjs:client _checkPing :: ping response received. Clearing flag and sending `pingreq` +1ms
  mqttjs:client _sendPacket :: (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240) ::  start +0ms
  mqttjs:client sendPacket :: packet: { cmd: 'pingreq' } +0ms
  mqttjs:client sendPacket :: emitting `packetsend` +1ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingreq"}
  mqttjs:client sendPacket :: writing to stream +0ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client sendPacket :: invoking cb +0ms
  mqttjs:client nop :: undefined +1ms
  mqttjs:client writable stream :: parsing buffer +16ms
  mqttjs:client parser :: on packet push to packets array. +1ms
  mqttjs:client work :: getting next packet in queue +0ms
  mqttjs:client work :: packet pulled from queue +0ms
  mqttjs:client _handlePacket :: emitting packetreceive +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingresp","retain":false,"qos":0,"dup":false,"length":0,"topic":null,"payload":null}
  mqttjs:client _checkPing :: checking ping... +1m
  mqttjs:client _checkPing :: ping response received. Clearing flag and sending `pingreq` +1ms
  mqttjs:client _sendPacket :: (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240) ::  start +0ms
  mqttjs:client sendPacket :: packet: { cmd: 'pingreq' } +0ms
  mqttjs:client sendPacket :: emitting `packetsend` +1ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingreq"}
  mqttjs:client sendPacket :: writing to stream +0ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client sendPacket :: invoking cb +0ms
  mqttjs:client nop :: undefined +0ms
  mqttjs:client writable stream :: parsing buffer +19ms
  mqttjs:client parser :: on packet push to packets array. +0ms
  mqttjs:client work :: getting next packet in queue +0ms
  mqttjs:client work :: packet pulled from queue +1ms
  mqttjs:client _handlePacket :: emitting packetreceive +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingresp","retain":false,"qos":0,"dup":false,"length":0,"topic":null,"payload":null}
  mqttjs:client _checkPing :: checking ping... +1m
  mqttjs:client _checkPing :: ping response received. Clearing flag and sending `pingreq` +1ms
  mqttjs:client _sendPacket :: (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240) ::  start +0ms
  mqttjs:client sendPacket :: packet: { cmd: 'pingreq' } +0ms
  mqttjs:client sendPacket :: emitting `packetsend` +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingreq"}
  mqttjs:client sendPacket :: writing to stream +3ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client sendPacket :: invoking cb +0ms
  mqttjs:client nop :: undefined +1ms
  mqttjs:client writable stream :: parsing buffer +37ms
  mqttjs:client parser :: on packet push to packets array. +0ms
  mqttjs:client work :: getting next packet in queue +1ms
  mqttjs:client work :: packet pulled from queue +0ms
  mqttjs:client _handlePacket :: emitting packetreceive +1ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingresp","retain":false,"qos":0,"dup":false,"length":0,"topic":null,"payload":null}
  mqttjs:client _checkPing :: checking ping... +1m
  mqttjs:client _checkPing :: ping response received. Clearing flag and sending `pingreq` +1ms
  mqttjs:client _sendPacket :: (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240) ::  start +0ms
  mqttjs:client sendPacket :: packet: { cmd: 'pingreq' } +0ms
  mqttjs:client sendPacket :: emitting `packetsend` +1ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"pingreq"}
  mqttjs:client sendPacket :: writing to stream +0ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client sendPacket :: invoking cb +0ms
  mqttjs:client nop :: undefined +0ms
  mqttjs:client _checkPing :: checking ping... +1m
  mqttjs:client _checkPing :: calling _cleanUp with force true +1ms
  mqttjs:client _cleanUp :: forced? true +0ms
  mqttjs:client _cleanUp :: (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240) :: destroying stream +0ms
  mqttjs:client _cleanUp :: client not disconnecting. Clearing and resetting reconnect. +3ms
  mqttjs:client _clearReconnect : clearing reconnect timer +1ms
  mqttjs:client _setupReconnect :: emit `offline` state +1ms
In etMqttServer : mqttConnect : test - on offline : client goes offline : clientId : NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240 
  mqttjs:client _setupReconnect :: set `reconnecting` to `true` +0ms
  mqttjs:client _setupReconnect :: setting reconnectTimer for 5000 ms +1ms
  mqttjs:client _cleanUp :: clearing pingTimer +0ms
  mqttjs:client (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240)stream :: on close +1ms
  mqttjs:client flushVolatile :: deleting volatile messages from the queue and setting their callbacks as error function +0ms
  mqttjs:client stream: emit close to MqttClient +0ms
  mqttjs:client close :: connected set to `false` +0ms
  mqttjs:client close :: clearing connackTimer +0ms
  mqttjs:client close :: clearing ping timer +0ms
  mqttjs:client close :: calling _setupReconnect +0ms
  mqttjs:client _setupReconnect :: doing nothing... +0ms
In etMqttServer : mqttConnect : test - on close : client disconnect with broker - undefined
  mqttjs:client reconnectTimer :: reconnect triggered! +5s
  mqttjs:client _reconnect: emitting reconnect to client +1ms
In etMqttServer : mqttConnect : test - on reconnect : client reconnect attempt is over : going to end connection
  mqttjs:client _reconnect: calling _setupStream +0ms
  mqttjs:client _setupStream :: calling method to clear reconnect +0ms
  mqttjs:client _clearReconnect : clearing reconnect timer +1ms
  mqttjs:client _setupStream :: using streamBuilder provided to client to create stream +0ms
  mqttjs calling streambuilder for ssl +10m
  mqttjs:tls port 31160 host test.clouzer.com rejectUnauthorized %b false +10m
  mqttjs:client _setupStream :: pipe stream to writable stream +3ms
  mqttjs:client _setupStream: sending packet `connect` +0ms
  mqttjs:client sendPacket :: packet: { cmd: 'connect' } +1ms
  mqttjs:client sendPacket :: emitting `packetsend` +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"connect"}
  mqttjs:client sendPacket :: writing to stream +1ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client !!connectTimeout hit!! Calling _cleanUp with force `true` +2m
  mqttjs:client _cleanUp :: forced? true +1ms
  mqttjs:client _cleanUp :: (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240) :: destroying stream +0ms
  mqttjs:client _cleanUp :: client not disconnecting. Clearing and resetting reconnect. +0ms
  mqttjs:client _clearReconnect : clearing reconnect timer +0ms
  mqttjs:client _setupReconnect :: setting reconnectTimer for 5000 ms +0ms
  mqttjs:client (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240)stream :: on close +1ms
  mqttjs:client flushVolatile :: deleting volatile messages from the queue and setting their callbacks as error function +0ms
  mqttjs:client stream: emit close to MqttClient +0ms
  mqttjs:client close :: connected set to `false` +0ms
  mqttjs:client close :: clearing connackTimer +0ms
  mqttjs:client close :: clearing ping timer +0ms
  mqttjs:client close :: calling _setupReconnect +0ms
  mqttjs:client _setupReconnect :: doing nothing... +0ms
In etMqttServer : mqttConnect : test - on close : client disconnect with broker - undefined
  mqttjs:client reconnectTimer :: reconnect triggered! +5s
  mqttjs:client _reconnect: emitting reconnect to client +1ms
In etMqttServer : mqttConnect : test - on reconnect : client reconnect attempt is over : going to end connection
  mqttjs:client _reconnect: calling _setupStream +0ms
  mqttjs:client _setupStream :: calling method to clear reconnect +1ms
  mqttjs:client _clearReconnect : clearing reconnect timer +0ms
  mqttjs:client _setupStream :: using streamBuilder provided to client to create stream +0ms
  mqttjs calling streambuilder for ssl +2m
  mqttjs:tls port 31160 host test.clouzer.com rejectUnauthorized %b false +2m
  mqttjs:client _setupStream :: pipe stream to writable stream +3ms
  mqttjs:client _setupStream: sending packet `connect` +0ms
  mqttjs:client sendPacket :: packet: { cmd: 'connect' } +1ms
  mqttjs:client sendPacket :: emitting `packetsend` +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"connect"}
  mqttjs:client sendPacket :: writing to stream +0ms
  mqttjs:client sendPacket :: writeToStream result true +1ms
  mqttjs:client writable stream :: parsing buffer +57ms
  mqttjs:client parser :: on packet push to packets array. +1ms
  mqttjs:client work :: getting next packet in queue +1ms
  mqttjs:client work :: packet pulled from queue +0ms
  mqttjs:client _handlePacket :: emitting packetreceive +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"connack","retain":false,"qos":0,"dup":false,"length":2,"topic":null,"payload":null,"sessionPresent":true,"returnCode":0}
  mqttjs:client _handleConnack +0ms
  mqttjs:client _setupPingTimer :: keepalive 60 (seconds) +0ms
  mqttjs:client connect :: sending queued packets +2ms
  mqttjs:client deliver :: entry undefined +0ms
  mqttjs:client _resubscribe +0ms
mqtt server connected!!
In etMqttServer : mqttConnect : test - connect : mqtt client successfully connected with broker 
IN CONNECT ======>[object Object]
  mqttjs:client (NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240)stream :: on close +5s
  mqttjs:client flushVolatile :: deleting volatile messages from the queue and setting their callbacks as error function +0ms
  mqttjs:client stream: emit close to MqttClient +0ms
  mqttjs:client close :: connected set to `false` +0ms
  mqttjs:client close :: clearing connackTimer +0ms
  mqttjs:client close :: clearing ping timer +0ms
  mqttjs:client close :: calling _setupReconnect +1ms
  mqttjs:client _setupReconnect :: emit `offline` state +0ms
In etMqttServer : mqttConnect : test - on offline : client goes offline : clientId : NODE_MQTT_PRODUCER-AWS_CLIENT-189104-1706161440240 
  mqttjs:client _setupReconnect :: set `reconnecting` to `true` +1ms
  mqttjs:client _setupReconnect :: setting reconnectTimer for 5000 ms +0ms
In etMqttServer : mqttConnect : test - on close : client disconnect with broker - undefined
  mqttjs:client reconnectTimer :: reconnect triggered! +5s
  mqttjs:client _reconnect: emitting reconnect to client +0ms
In etMqttServer : mqttConnect : test - on reconnect : client reconnect attempt is over : going to end connection
  mqttjs:client _reconnect: calling _setupStream +1ms
  mqttjs:client _setupStream :: calling method to clear reconnect +0ms
  mqttjs:client _clearReconnect : clearing reconnect timer +0ms
  mqttjs:client _setupStream :: using streamBuilder provided to client to create stream +1ms
  mqttjs calling streambuilder for ssl +10s
  mqttjs:tls port 31160 host test.clouzer.com rejectUnauthorized %b false +10s
  mqttjs:client _setupStream :: pipe stream to writable stream +2ms
  mqttjs:client _setupStream: sending packet `connect` +0ms
  mqttjs:client sendPacket :: packet: { cmd: 'connect' } +0ms
  mqttjs:client sendPacket :: emitting `packetsend` +1ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"connect"}
  mqttjs:client sendPacket :: writing to stream +0ms
  mqttjs:client sendPacket :: writeToStream result true +0ms
  mqttjs:client writable stream :: parsing buffer +72ms
  mqttjs:client parser :: on packet push to packets array. +0ms
  mqttjs:client work :: getting next packet in queue +0ms
  mqttjs:client work :: packet pulled from queue +0ms
  mqttjs:client _handlePacket :: emitting packetreceive +0ms
In etMqttServer : mqttConnect : test - on packetsend : {"cmd":"connack","retain":false,"qos":0,"dup":false,"length":2,"topic":null,"payload":null,"sessionPresent":true,"returnCode":0}
  mqttjs:client _handleConnack +1ms
  mqttjs:client _setupPingTimer :: keepalive 60 (seconds) +0ms
  mqttjs:client connect :: sending queued packets +1ms
  mqttjs:client deliver :: entry undefined +0ms
  mqttjs:client _resubscribe +0ms
mqtt server connected!!
In etMqttServer : mqttConnect : test - connect : mqtt client successfully connected with broker 
IN CONNECT ======>[object Object]

Current mqtt version: 4.3.7

Now, I try with latest version and let you know

@robertsLando sorry fo the late reply

Thanks for your response.

[robertsLando]

Current mqtt version: 4.3.7

Please let me know if the bug persists with latest version. Also please post new logs with the latest version, by checking your logs it seems to me the issue is kind of related to the keepalive/restart issue I recently fixed in #1779

[dasaripravin-developer]

@robertsLando

This issue is resolve, As discussed with my mqtt broker team, their is an load balancing issue with broker. large number of client connected with single broker and rest of the broker instances are cloudn't taken connection. After resolving the issue, it working fine. Therefore in my conslusion this issue from broker end.

As you mention this issue is related to keepalive so for the safer side I'll increase keepalive time in client configuration. I am closing this issue now. If anyone face the same issue then please reopen it.

Thanks for your response @robertsLando