search

shamblett / mqtt_client

A server and browser based MQTT client for dart
Other
548 stars 176 forks source link

Client disconnects when unsubscribing from topic #165

Closed chiragmittal19 closed 4 years ago

chiragmittal19 commented 4 years ago

https://github.com/shamblett/mqtt_client/blob/70e1091a288225439ef3f1ed55b2851b97c5c15f/lib/src/connectionhandling/mqtt_client_mqtt_connection.dart#L104

This method is called when a topic is unsubscribed. But what is the purpose of closing client on un-subscription? If I want to unsubscribe from a topic and keep the client connected, how can I do that?

shamblett commented 4 years ago

This should only be called when the broker disconnects, not when you unsubscribe from a topic, could you supply the full log output from when you unsubscribe.

chiragmittal19 commented 4 years ago 
I/flutter ( 6246): 2020-03-31 11:15:26.357247 -- MqttConnectionHandler::sendMessage - MQTTMessage of type MqttMessageType.unsubscribe

I/flutter ( 6246): Header: MessageType = MqttMessageType.unsubscribe, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0

I/flutter ( 6246): Unsubscribe VariableHeader Variable Header: MessageIdentifier={3}

I/flutter ( 6246): Payload: Unsubscription [{1}]

I/flutter ( 6246): {{ Topic={8888}}

I/flutter ( 6246): 
I/flutter ( 6246): 2020-03-31 11:15:26.362633 -- MqttConnectionHandler::sendMessage - MQTTMessage of type MqttMessageType.unsubscribe

I/flutter ( 6246): Header: MessageType = MqttMessageType.unsubscribe, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0

I/flutter ( 6246): Unsubscribe VariableHeader Variable Header: MessageIdentifier={4}

I/flutter ( 6246): Payload: Unsubscription [{1}]

I/flutter ( 6246): {{ Topic={0005}}

I/flutter ( 6246): 
I/flutter ( 6246): 2020-03-31 11:15:26.443359 -- MqttConnection::_onDone - calling disconnected callback

[log] MQTT_Client disconnected

The last log statement is inside my onDisconnected callback method. Just above that, you can see the _onDone being called. Also, I did not receive any onUnsubscribed callback.

chiragmittal19 commented 4 years ago

If I comment out the code inside _onDone method, everything works fine. The broker stays connected and I receive onUnsubscribed callback. So, I guess, the issue is not with broker.

shamblett commented 4 years ago

The above log shows an unsubscribe twice, once for topic 0008 and once for topic 0005, neither have unsubscribe responses yet, which unsubscribe callback works when you comment out onDone?

chiragmittal19 commented 4 years ago

The one that I provide while creating a client. Btw, I'm using version 5.6.2

shamblett commented 4 years ago

Sorry I wasn't clear, which topic(s) do you get the unsubscribe callback for? The first topic(0008), the second(0005) or both?

chiragmittal19 commented 4 years ago 
I/flutter ( 9877): 2020-03-31 12:07:32.861428 -- MqttConnectionHandler::sendMessage - MQTTMessage of type MqttMessageType.unsubscribe
I/flutter ( 9877): Header: MessageType = MqttMessageType.unsubscribe, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0
I/flutter ( 9877): Unsubscribe VariableHeader Variable Header: MessageIdentifier={5}
I/flutter ( 9877): Payload: Unsubscription [{1}]
I/flutter ( 9877): {{ Topic={8888}}
I/flutter ( 9877): 
I/flutter ( 9877): 2020-03-31 12:07:32.863426 -- MqttConnectionHandler::sendMessage - MQTTMessage of type MqttMessageType.unsubscribe
I/flutter ( 9877): Header: MessageType = MqttMessageType.unsubscribe, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0
I/flutter ( 9877): Unsubscribe VariableHeader Variable Header: MessageIdentifier={6}
I/flutter ( 9877): Payload: Unsubscription [{1}]
I/flutter ( 9877): {{ Topic={0005}}
I/flutter ( 9877):

These are the logs after commenting out _onDone. I'm sorry, my bad. I'm not receiving any onUnsubscribed callback even in this case.

shamblett commented 4 years ago

This makes a bit more sense, looks as though the broker is upset somehow with either the first or second unsubscribe message and closing the connection. OK, is this the first time you have tried to unsubscribe or have you tried this before and it worked, i.e. have you had any unsubscribe requests that have worked?

chiragmittal19 commented 4 years ago

No, this is the first time I'm doing this.

I/flutter ( 9877): 2020-03-31 12:35:47.173643 -- MqttConnectionHandler::sendMessage - MQTTMessage of type MqttMessageType.pingRequest
I/flutter ( 9877): Header: MessageType = MqttMessageType.pingRequest, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0
E/flutter ( 9877): [ERROR:flutter/lib/ui/ui_dart_state.cc(157)] Unhandled Exception: SocketException: OS Error: Broken pipe, errno = 32, address = a1x3rlf******-ats.iot.ap-south-1.amazonaws.com, port = 4***5
E/flutter ( 9877): null

These logs print a few seconds after unsubscribing. Some enlightening errors.

shamblett commented 4 years ago

Yes this is to be expected, the client has disconnected/broker has closed and this is its last ping request which of course fails it looks as though AWS doesn't like the unsubscribe message I'll see if I can dig around a bit, what MQTT version are you set to 3.1 or 3.1.1?

chiragmittal19 commented 4 years ago

AWS says - The AWS IoT message broker implementation is based on MQTT version 3.1.1

Reference - https://docs.aws.amazon.com/iot/latest/developerguide/mqtt.html

shamblett commented 4 years ago

Yes, I meant the client protocol, the client can be set to use MQTT 3.1 or 3.1.1, it defaults to 3.1 unless you perform a setProtocolV311() on the client when you initialise it. If you are not doing this please try it.

chiragmittal19 commented 4 years ago 
I/zygote  (13451): Do partial code cache collection, code=30KB, data=30KB
I/zygote  (13451): After code cache collection, code=30KB, data=30KB
I/zygote  (13451): Increasing code cache capacity to 128KB
I/flutter (13451): 2020-03-31 13:28:06.286865 -- MqttConnectionHandler::sendMessage - MQTTMessage of type MqttMessageType.unsubscribe
I/flutter (13451): Header: MessageType = MqttMessageType.unsubscribe, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0
I/flutter (13451): Unsubscribe VariableHeader Variable Header: MessageIdentifier={3}
I/flutter (13451): Payload: Unsubscription [{1}]
I/flutter (13451): {{ Topic={8888}}
I/flutter (13451): 
I/flutter (13451): 2020-03-31 13:28:06.292085 -- MqttConnectionHandler::sendMessage - MQTTMessage of type MqttMessageType.unsubscribe
I/flutter (13451): Header: MessageType = MqttMessageType.unsubscribe, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0
I/flutter (13451): Unsubscribe VariableHeader Variable Header: MessageIdentifier={4}
I/flutter (13451): Payload: Unsubscription [{1}]
I/flutter (13451): {{ Topic={0005}}
I/flutter (13451): 
I/flutter (13451): 2020-03-31 13:28:06.365690 -- MqttConnection::_onData
I/flutter (13451): 2020-03-31 13:28:06.370608 -- MqttConnection::_onData - message received MQTTMessage of type MqttMessageType.unsubscribeAck
I/flutter (13451): Header: MessageType = MqttMessageType.unsubscribeAck, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 2
I/flutter (13451): UnsubscribeAck Variable Header: MessageIdentifier={3}
I/flutter (13451): 2020-03-31 13:28:06.371288 -- MqttConnection::_onData - message processed
[log] MQTT_Client unsubscribed from 8888
I/flutter (13451): 2020-03-31 13:28:06.409227 -- MqttConnection::_onData
I/flutter (13451): 2020-03-31 13:28:06.409928 -- MqttConnection::_onData - message received MQTTMessage of type MqttMessageType.unsubscribeAck
I/flutter (13451): Header: MessageType = MqttMessageType.unsubscribeAck, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 2
I/flutter (13451): UnsubscribeAck Variable Header: MessageIdentifier={4}
I/flutter (13451): 2020-03-31 13:28:06.410314 -- MqttConnection::_onData - message processed
[log] MQTT_Client unsubscribed from 0005
I/flutter (13451): 2020-03-31 13:28:20.731693 -- MqttConnectionHandler::sendMessage - MQTTMessage of type MqttMessageType.pingRequest
I/flutter (13451): Header: MessageType = MqttMessageType.pingRequest, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0
I/flutter (13451): 2020-03-31 13:28:20.777570 -- MqttConnection::_onData
I/flutter (13451): 2020-03-31 13:28:20.779373 -- MqttConnection::_onData - message received MQTTMessage of type MqttMessageType.pingResponse
I/flutter (13451): Header: MessageType = MqttMessageType.pingResponse, Duplicate = false, Retain = false, Qos = MqttQos.atMostOnce, Size = 0
I/flutter (13451): 2020-03-31 13:28:20.779858 -- MqttConnection::_onData - message processed
[log] MQTT_Client received ping response

My new logs! Never knew MQTT version will make a difference. Thank you so much man. Hats off!

shamblett commented 4 years ago

Yes, some brokers are very picky about this, others not so.