Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Bug]: Does not start reconnect timer on connection error #1947

Closed
mgabeler-lee-6rs opened this issue Oct 10, 2024 · 5 comments · Fixed by #1948
Closed

[Bug]: Does not start reconnect timer on connection error #1947

mgabeler-lee-6rs opened this issue Oct 10, 2024 · 5 comments · Fixed by #1948
Labels

Comments

@mgabeler-lee-6rs
Copy link
Contributor

MQTTjs Version

5.10.1

Broker

emqx

Environment

NodeJS

Description

If a connection attempt is met with a connack packet with an error (e.g. an auth error), no reconnect is attempted.

With expiring auth keys, such connack errors are expected. Our app is setup to trigger auth refresh on those errors using the suggested methods from other issues, but the client never actually sets up the reconnect timer in this case.

Minimal Reproduction

const mqtt = require('mqtt');

let auth: { username: string; password: string; };
// auth setup elided. Assume it happens to start with an expired token that needs to be renewed, but we don't know that yet.
const client = mqtt.connect('ssl://our.mqtt.broker:443', {
	...auth,
	clientId,
	log: mqttLogFunc,
	protocolVersion: 5,
	reconnectPeriod: 1000,
	keepalive: 60,
	connectTimeout: 5_000,
});
client.on('connect', () => console.log('connected'));
client.on('error', () => {
  rewnewAuth(client); // updates client.options following e.g. https://github.com/mqttjs/MQTT.js/issues/533#issuecomment-625388090
});

I expect this to keep retrying, but it does not.

Debug logs

These logs are from a test hitting our real broker with bogus creds. The test is nearly identical to the repro above. I have intentionally provided a wrong password in the test to reproduce the issue. I have also elided the username, client id, and broker hostname.

  mqttjs connecting to an MQTT broker... +0ms
  mqttjs:client MqttClient :: version: 5.10.1 +0ms
  mqttjs:client MqttClient :: environment node +1ms
  mqttjs:client MqttClient :: options.protocol ssl +0ms
  mqttjs:client MqttClient :: options.protocolVersion 5 +0ms
  mqttjs:client MqttClient :: options.username CENSORED +0ms
  mqttjs:client MqttClient :: options.keepalive 60 +0ms
  mqttjs:client MqttClient :: options.reconnectPeriod 1000 +0ms
  mqttjs:client MqttClient :: options.rejectUnauthorized undefined +0ms
  mqttjs:client MqttClient :: options.properties.topicAliasMaximum undefined +0ms
  mqttjs:client MqttClient :: clientId CENSORED +0ms
  mqttjs:client MqttClient :: setting up stream +1ms
  mqttjs:client connect :: calling method to clear reconnect +1ms
  mqttjs:client _clearReconnect : clearing reconnect timer +0ms
  mqttjs:client connect :: using streamBuilder provided to client to create stream +0ms
  mqttjs calling streambuilder for ssl +19ms
  mqttjs:tls port 443 host our.mqtt.broker rejectUnauthorized %b true +0ms
  mqttjs:client connect :: pipe stream to writable stream +1ms
  mqttjs:client connect: sending packet `connect` +1ms
  mqttjs:client _writePacket :: packet: {
  mqttjs:client   cmd: 'connect',
  mqttjs:client   protocolId: 'MQTT',
  mqttjs:client   protocolVersion: 5,
  mqttjs:client   clean: true,
  mqttjs:client   clientId: 'CENSORED',
  mqttjs:client   keepalive: 60,
  mqttjs:client   username: 'CENSORED',
  mqttjs:client   password: 'fake',
  mqttjs:client   properties: undefined
  mqttjs:client } +0ms
  mqttjs:client _writePacket :: emitting `packetsend` +0ms
  mqttjs:client _writePacket :: writing to stream +0ms
  mqttjs:client _writePacket :: writeToStream result true +26ms
  mqttjs:client writable stream :: parsing buffer +267ms
  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
  mqttjs:client _handleConnack +0ms
// test logs ErrorWithReasonCode: Connection refused: Not authorized at this point

MQTT logs nothing more after this, since ... it's not doing anything.

@robertsLando
Copy link
Member

This reminds me of the opposite a user asked for, I'm not sure but this may have changed in one of the latest versions (or maybe I remember this wrong). Could you try to check If there is a specific version that introduced this?

@mgabeler-lee-6rs
Copy link
Contributor Author

I went back to v5.0.0 and it did the same thing. Going back into v4.x is hard to integrate with the existing test code I have due to increasing changes in the typescript types.

Rummaging through the source history, I finally found this: https://github.com/mqttjs/MQTT.js/pull/1076/files?diff=unified&w=1#diff-ca407d959d33ce92a7f7efee354a5ea5e6e61fcd797d32c04205e429a074ed54L256-L259

It seems vaguely relevant if the connection error would have triggered the close event in that case, but I'm not sure.

Other than that, I don't see much sign that the reconnect timer would have ever been setup in the case of the initial connack packet reporting an error.

@robertsLando
Copy link
Member

@mgabeler-lee-6rs would you like to submit a PR? I think this could also be opt-in behind a connect option

@mgabeler-lee-6rs
Copy link
Contributor Author

I'll work one up 👍

@mgabeler-lee-6rs
Copy link
Contributor Author

I've started a draft, it needs tests & some thought on naming at least (the option name seems ... quite verbose right now): #1948

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

Successfully merging a pull request may close this issue.

2 participants