eclipse-paho / paho.mqtt.android

MQTT Android
Other
2.95k stars 893 forks source link

After reconnection, the callbacks will be called multiple times. #5

Open jpwsutton opened 8 years ago

jpwsutton commented 8 years ago

migrated from Bugzilla #482634 status UNCONFIRMED severity normal in component MQTT-Android for 1.2 Reported in version v0.5 on platform Other Assigned to: James Sutton

Original attachment names and IDs:

On 2015-11-19 19:02:34 -0500, Luxi Liu wrote:

Hi There,

I'm using 'org.eclipse.paho:org.eclipse.paho.client.mqttv3:1.0.3-SNAPSHOT' and 'org.eclipse.paho:org.eclipse.paho.android.service:1.0.3-SNAPSHOT' to develop an Android app, which subscribes topics for messages from our own MQTT server.

As the MQTT server is not pingable, if there's no message coming, after the keep-alive-interval, the connection will be lost. On user's appropriate operation, the app will re-connect to the server if MqttAndroidClient.isConnected() returns false.

Then problem is: The callback onSuccess() of MqttAndroidClient.connect() for this reconnection attempt, will be called twice. And the callback messageArrived() for the subscribed message coming through, will be called twice as well. If the app re-connects for the 3rd time, the callbacks will be called 3 times; 4th, 4 times; 5th, 5 times; ...

I tried MqttAndroidClient.setKeepAliveInterval(), but it seems this API doesn't work at all, because no matter what value I set, the connection is always lost after 60 secs.

Initially, I used the libraries of 1.0.2 in release repo and I met this problem. Still no luck after changing to 1.0.3 in snapshot repo.

I found a similar bug https://bugs.eclipse.org/bugs/show_bug.cgi?id=462619, which was already fixed. I'm not sure whether they're related or not.

Thank you!

On 2015-11-19 19:20:41 -0500, Luxi Liu wrote:

Confirm that SNAPSHOT has fixed this issue. But setKeepAliveInterval() still doesn't work in this case.

Thanks.

On 2015-11-25 06:37:53 -0500, James Sutton wrote:

Hi Luxi,

The Keep Alive value is only sent when the client connects to the server. Once that has happened, that value will be used for the remainder of the connection and cannot be changed.

It sounds like you're trying to change the keep alive after you have connected which would not have any effect on the connection. But MqttAndroidClient doesn't have a setKeepAliveInterval so I'm guessing that you're actually talking about MqttConnectOptions right?

On 2015-11-25 18:21:59 -0500, Luxi Liu wrote:

(In reply to James Sutton from comment # 2)

Hi Luxi,

The Keep Alive value is only sent when the client connects to the server. Once that has happened, that value will be used for the remainder of the connection and cannot be changed.

It sounds like you're trying to change the keep alive after you have connected which would not have any effect on the connection. But MqttAndroidClient doesn't have a setKeepAliveInterval so I'm guessing that you're actually talking about MqttConnectOptions right?

Yes, it's MqttConnectOptions. The code is as below,

MqttConnectOptions mqttConnectOptions = new MqttConnectOptions(); mqttConnectOptions.setUserName(getUsername()); mqttConnectOptions.setPassword(getAccessToken().toCharArray()); mqttConnectOptions.setKeepAliveInterval(60 * 5);

mMqttAndroidClient.connect(mqttConnectOptions(), null, this);

No matter what value I give to setKeepAliveInterval(), the connected connection always connectionLost() after 60 sec, which is default value.

On 2015-11-27 08:34:04 -0500, James Sutton wrote:

I've not been able to recreate this on my nexus 5 with the sample app. What type of MQTT broker are you using? I've tested with the Mosquitto Broker on iot.eclipse.org which seems to work well.

On 2015-11-27 17:43:33 -0500, Luxi Liu wrote:

(In reply to James Sutton from comment # 4)

I've not been able to recreate this on my nexus 5 with the sample app. What type of MQTT broker are you using? I've tested with the Mosquitto Broker on iot.eclipse.org which seems to work well.

Try with an unpingable broker

On 2015-11-30 04:50:17 -0500, James Sutton wrote:

(In reply to Luxi Liu from comment # 5)

(In reply to James Sutton from comment # 4)

I've not been able to recreate this on my nexus 5 with the sample app. What type of MQTT broker are you using? I've tested with the Mosquitto Broker on iot.eclipse.org which seems to work well.

Try with an unpingable broker

If a broker does not respond to a PINGREQ then it is not compliant with the MQTTv3.1.1 spec and so would not be supported. http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os.html#_Toc398718081

What broker does not respond to PINGREQs and why would you want to use it over other types?

On 2015-11-30 19:19:42 -0500, Luxi Liu wrote:

(In reply to James Sutton from comment # 6)

(In reply to Luxi Liu from comment # 5)

(In reply to James Sutton from comment # 4)

I've not been able to recreate this on my nexus 5 with the sample app. What type of MQTT broker are you using? I've tested with the Mosquitto Broker on iot.eclipse.org which seems to work well.

Try with an unpingable broker

If a broker does not respond to a PINGREQ then it is not compliant with the MQTTv3.1.1 spec and so would not be supported. http://docs.oasis-open.org/mqtt/mqtt/v3.1.1/os/mqtt-v3.1.1-os. html#_Toc398718081

What broker does not respond to PINGREQs and why would you want to use it over other types?

It's an internally used server.

So for an unable-to-ping server, setKeepAliveInterval() cannot work?

The actual problem becomes:

  1. Connected to this unable-to-ping server with setKeepAliveInterval(300), 2. There's no message coming through within 300 secs, and at the same time, the ping message is not responded.
  2. After 60 secs, which is the default, the connection is lost.

On 2015-12-01 04:07:00 -0500, James Sutton wrote:

Right, I was thrown because in your example you were setting a keep alive value. If any keepalive interval is set, the client will also disconnect because the server is not responding. Set the keepalive interval to 0 which will disable keepalive processing in the client.

On 2015-12-01 08:21:27 -0500, Luxi Liu wrote:

(In reply to James Sutton from comment # 8)

Right, I was thrown because in your example you were setting a keep alive value. If any keepalive interval is set, the client will also disconnect because the server is not responding. Set the keepalive interval to 0 which will disable keepalive processing in the client.

Unfortunately, setKeepAliveInterval(0) doesn't work, after 60 sec, the connection is still lost.

On 2015-12-01 08:44:12 -0500, Luxi Liu wrote:

The connection is SSL via port 8883.

On 2015-12-01 08:51:36 -0500, James Sutton wrote:

Created attachment 258391 Log file showing connection with keepalive of 0

On 2015-12-01 08:55:03 -0500, James Sutton wrote:

Comment on attachment 258391 Log file showing connection with keepalive of 0

12-01 13:43:22.667 24706-25857/org.eclipse.paho.android.sample D/AlarmPingSender: Register alarmreceiver to MqttServiceMqttService.pingSender.AndroidExampleClient 12-01 13:43:22.669 24706-25857/org.eclipse.paho.android.sample D/AlarmPingSender: Schedule next alarm at 1448977402669 12-01 13:43:22.674 24706-24706/org.eclipse.paho.android.sample I/ActionListener: L73AFSOP-iot.eclipse.org-AndroidExampleClient connected. 12-01 13:43:22.674 24706-24706/org.eclipse.paho.android.sample I/ActionListener: Auto-subscribing to: /jsutton23/test@ QoS: 0 12-01 13:43:27.672 24706-24706/org.eclipse.paho.android.sample D/AlarmPingSender: Ping 1 times. 12-01 13:43:27.672 24706-24706/org.eclipse.paho.android.sample D/AlarmPingSender: Check time :1448977407672 12-01 13:43:55.006 24706-24706/org.eclipse.paho.android.sample I/System.out: GOT A MESSAGE in history Incoming Message Test 12-01 13:43:55.006 24706-24706/org.eclipse.paho.android.sample I/System.out: M: 1 12-01 13:43:55.014 24706-24706/org.eclipse.paho.android.sample I/MqttCallbackHandler: Received message Incoming Message Test
Topic: /jsutton23/test;qos:0;retained:false 12-01 13:48:13.437 24706-24706/org.eclipse.paho.android.sample I/System.out: GOT A MESSAGE in history Incoming Message Test 12-01 13:48:13.438 24706-24706/org.eclipse.paho.android.sample I/System.out: M: 2 12-01 13:48:13.439 24706-24706/org.eclipse.paho.android.sample I/MqttCallbackHandler: Received message Incoming Message Test
Topic: /jsutton23/test;qos:0;retained:false 12-01 13:48:23.616 24706-30786/org.eclipse.paho.android.sample D/AlarmPingSender: Unregister alarmreceiver to MqttServiceAndroidExampleClient

On 2015-12-01 08:56:14 -0500, Luxi Liu wrote:

(In reply to James Sutton from comment # 12)

Comment on attachment 258391 [details] Log file showing connection with keepalive of 0

12-01 13:43:22.667 24706-25857/org.eclipse.paho.android.sample D/AlarmPingSender: Register alarmreceiver to MqttServiceMqttService.pingSender.AndroidExampleClient 12-01 13:43:22.669 24706-25857/org.eclipse.paho.android.sample D/AlarmPingSender: Schedule next alarm at 1448977402669 12-01 13:43:22.674 24706-24706/org.eclipse.paho.android.sample I/ActionListener: L73AFSOP-iot.eclipse.org-AndroidExampleClient connected. 12-01 13:43:22.674 24706-24706/org.eclipse.paho.android.sample I/ActionListener: Auto-subscribing to: /jsutton23/test@ QoS: 0 12-01 13:43:27.672 24706-24706/org.eclipse.paho.android.sample D/AlarmPingSender: Ping 1 times. 12-01 13:43:27.672 24706-24706/org.eclipse.paho.android.sample D/AlarmPingSender: Check time :1448977407672 12-01 13:43:55.006 24706-24706/org.eclipse.paho.android.sample I/System.out: GOT A MESSAGE in history Incoming Message Test 12-01 13:43:55.006 24706-24706/org.eclipse.paho.android.sample I/System.out: M: 1 12-01 13:43:55.014 24706-24706/org.eclipse.paho.android.sample I/MqttCallbackHandler: Received message Incoming Message Test
Topic: /jsutton23/test;qos:0;retained:false 12-01 13:48:13.437 24706-24706/org.eclipse.paho.android.sample I/System.out: GOT A MESSAGE in history Incoming Message Test 12-01 13:48:13.438 24706-24706/org.eclipse.paho.android.sample I/System.out: M: 2 12-01 13:48:13.439 24706-24706/org.eclipse.paho.android.sample I/MqttCallbackHandler: Received message Incoming Message Test
Topic: /jsutton23/test;qos:0;retained:false 12-01 13:48:23.616 24706-30786/org.eclipse.paho.android.sample D/AlarmPingSender: Unregister alarmreceiver to MqttServiceAndroidExampleClient

In you log, you have got messages coming. Have you try if no message coming and going at all?

On 2015-12-01 08:57:19 -0500, Luxi Liu wrote:

  1. setkeepalive(0)
  2. makre sure no message received or sent. after 60 secs, the connection will be lost

On 2015-12-01 09:03:58 -0500, James Sutton wrote:

So I gave it a try where I used the Sample App to connect to the mosquitto broker at iot.eclipse.org with a keepalive of 0.

As you can see in the attached log, the client connected to the broker at 13:43, auto subscribed to a topic and began a ping which immediately stopped because keepalive was set to 0. Note: It did not re-schedule. I then sent a test message, then waited about 5 minutes before sending another to make sure that the client was still connected and then disconnected.

If the connection is dropping for you, then it could be a genuine connectivity issue or an issue with your broker.

Do you have any logs to support that the keepalive value is not being honoured?

On 2015-12-02 01:22:18 -0500, Luxi Liu wrote:

(In reply to James Sutton from comment # 15)

So I gave it a try where I used the Sample App to connect to the mosquitto broker at iot.eclipse.org with a keepalive of 0.

As you can see in the attached log, the client connected to the broker at 13:43, auto subscribed to a topic and began a ping which immediately stopped because keepalive was set to 0. Note: It did not re-schedule. I then sent a test message, then waited about 5 minutes before sending another to make sure that the client was still connected and then disconnected.

If the connection is dropping for you, then it could be a genuine connectivity issue or an issue with your broker.

Do you have any logs to support that the keepalive value is not being honoured?

I can only see

D/AlarmPingSender: Unregister alarmreceiver to MqttServiceau.com.netcabs.oiii.352136069698666 D/ContentManager: MqttAndroidClient: connectionLost(In reply to James Sutton from comment # 15)

So I gave it a try where I used the Sample App to connect to the mosquitto broker at iot.eclipse.org with a keepalive of 0.

As you can see in the attached log, the client connected to the broker at 13:43, auto subscribed to a topic and began a ping which immediately stopped because keepalive was set to 0. Note: It did not re-schedule. I then sent a test message, then waited about 5 minutes before sending another to make sure that the client was still connected and then disconnected.

If the connection is dropping for you, then it could be a genuine connectivity issue or an issue with your broker.

Do you have any logs to support that the keepalive value is not being honoured?

I only have the following log

D/AlarmPingSender: Unregister alarmreceiver to MqttServiceau.com.abc.def.352136069698666 D/ContentManager: MqttAndroidClient: connectionLost

After 60 sec, the connect is lost. How can I get more detail log?

On 2015-12-02 05:33:12 -0500, James Sutton wrote:

Unfortunately for connectionLost there aren't really any more logs that could be shown. In your connectionLost callback, you could take the exception and print it to your console.

@Override public void connectionLost(Throwable cause) { if (cause != null) { System.out.println("Connection Lost: " + cause.getMessage());
} }

As you are also using a custom broker, you could try adding your own logging to that to look at the life cycle of the client. It may explain why your client is loosing the connection.

I recommend that you also test with iot.eclipse.org or a mosquitto broker to see if the client behaves the same way. If the client does not lose connection after 60 seconds then it is likely that the issue lies with either the route between the client and broker or the broker itself.

On 2015-12-17 09:55:35 -0500, James Sutton wrote:

Hi, Any Luck with this?

On 2015-12-21 22:11:42 -0500, Luxi Liu wrote:

(In reply to James Sutton from comment # 18)

Hi, Any Luck with this?

Hi,

I believe something's different with our own MQTT server, because the issue is not found with any other brokers

On 2015-12-22 06:36:31 -0500, Ian Craggs wrote:

Hi, James is on vacation now until January.

What would really help is to find out why the server is disconnecting the client. Depending on the MQTT server, there should be a log message or other explanation available. If this doesn't happen with any other MQTT server, maybe the server has a problem, or a mismatch in expectations between the client and server?

On 2015-12-22 16:14:56 -0500, Luxi Liu wrote:

(In reply to Ian Craggs from comment # 20)

Hi, James is on vacation now until January.

What would really help is to find out why the server is disconnecting the client. Depending on the MQTT server, there should be a log message or other explanation available. If this doesn't happen with any other MQTT server, maybe the server has a problem, or a mismatch in expectations between the client and server?

But I tried a ruby testing script, to connect first, sleep for more than 60 secs, then publish and receive message. The script can work, no auto disconnected issue

dorkmania commented 7 years ago

Hi I'm observing the same issue in version 1.1.1 of the paho.mqtt.android client. I'm using mosca as my MQTT Broker. I'll try switching to Mosquitto Broker to see if it fixes the issue and update.

jpwsutton commented 7 years ago

@dorkmania Hi, If you do see this, could you provide some steps to recreate please?

dorkmania commented 7 years ago

@jpwsutton I'm invoking MqttAndroidClient.publish in the onSuccess case of the callback from MqttAndroidClient.connect in the onResume method of my activity. It seems that publish seems to trigger failure to connect (still need to confirm this) as far as the application is concerned and re-invokes connect. The publish message however, still seems to go through. I'm using MQTT for a client server use-case as compared to an IoT one. This might just be a case of the library working as designed but being a bad fit for my task. Your thoughts?

jpwsutton commented 7 years ago

Interesting, have you got automatic reconnect or disconnected publishing enabled?

dorkmania commented 7 years ago

@jpwsutton I'm not explicitly setting these if that's what you mean. Any way to confirm that these are disabled?

rajshrip31 commented 6 years ago

Hi, I am using 'org.eclipse.paho:org.eclipse.paho.client.mqttv3:1.2.0' for messaging. I connect to mqtt broker using single client id in my whole application. When I manually switch off wifi, client gets disconnected and when wifi again available I try to connect the broker again, on that call I get 2 callback of success. It's happening with failure case as well. When I use different client id for every connection I get only single callback response. I want to connect using same client id every time, is there any solution to resolve this issue. I also tried with SNAPSHOT version, but still issue is reproducing. I am a new bee for Mqtt, any guidance will be really helpful for me.

AlexandruDev commented 1 year ago

Having the same issue on my Android TV app. I open my app, I press the Home button from my remote, then I open my app again. The MQTT callbacks are called twice. If I do this again then I get the same callbacks 3 times and so on... I initialise the MQTT inside the onCreate() of my MainActivity class.

Any idea what's wrong here?

I tried to disconnect the clients when the app enters Stop() method but with no success:

 fun disconnect() {
        for ((_, client) in clients) {
            client.disconnect()
        }
    }