eclipse-paho / eclipse-paho/paho.mqtt.java
waitForCompletion() interrupted when called from connectionLost() / - 1.2.0 regression (not present in 1.1.0)
- Dominant language
- Java
- Stars
- 2.3k
- Forks
- 919
- PR merge metrics
- No merged PRs in 30d
Description
Please fill out the form below before submitting, thank you!
- [ No ] Bug exists Release Version 1.1.0
- [ Yes ] Bug exists Release Version 1.2.0 ( Master Branch)
- [ Yes ] Bug exists in MQTTv3 Client on Snapshot Version 1.2.1-SNAPSHOT (Develop Branch)
- [ Cannot verify, broker used doesn't support MQTTv5 ] Bug exists in MQTTv5 Client on Snapshot Version 1.2.1-SNAPSHOT (Develop Branch)
I am using a Solace broker.
Using Paho 1.1.0:
> 2018-07-27T14:45:18.918+00:00 vmr-133-17 event: CLIENT: CLIENT_CLIENT_CONNECT_MQTT: default #mqtt/JavaSample/11663 Client (967) #mqtt/JavaSample/11663 username default OriginalClientUsername(default) ClientId (JavaSample) connected to 192.168.133.17:1883 from 192.168.131.211:51724 SslVersion() SslCipher() authScheme(Basic) Clean(1) Will(0) SslRevocation(Not Checked)
ACTION (while application sleeping): Disconnect client from broker's perspective:
vmr-133-17(admin/client)# disconnect
Number of clients disconnected: 1.
> 2018-07-27T14:45:21.337+00:00 vmr-133-17 event: CLIENT: CLIENT_CLIENT_DISCONNECT_MQTT: default #mqtt/JavaSample/11663 Client (967) #mqtt/JavaSample/11663 username default ClientId (JavaSample) reason(Forced Logout) final statistics - dp(1, 1, 0, 0, 1, 1, 24, 4, 0, 0, 24, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) conn(0, 0, 192.168.131.211:51724, ESTAB, 0, 0, 0) mqtt(1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0), SslVersion(), SslCipher(), WillSent(0)
> 2018-07-27T14:45:21.341+00:00 vmr-133-17 event: CLIENT: CLIENT_CLIENT_CONNECT_MQTT: default #mqtt/JavaSample/11665 Client (968) #mqtt/JavaSample/11665 username default OriginalClientUsername(default) ClientId (JavaSample) connected to 192.168.133.17:1883 from 192.168.131.211:51725 SslVersion() SslCipher() authScheme(Basic) Clean(1) Will(0) SslRevocation(Not Checked)
> 2018-07-27T14:45:28.921+00:00 vmr-133-17 event: CLIENT: CLIENT_CLIENT_DISCONNECT_MQTT: default #mqtt/JavaSample/11665 Client (968) #mqtt/JavaSample/11665 username default ClientId (JavaSample) reason(Client Disconnect Received) final statistics - dp(2, 1, 0, 0, 2, 1, 26, 4, 0, 0, 26, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) conn(0, 0, 192.168.131.211:51725, ESTAB, 0, 0, 0) mqtt(1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1), SslVersion(), SslCipher(), WillSent(0)
Client reconnected successfully, application ran cleanly:
> Connecting to broker: tcp://192.168.133.17:1883
> Connected
> connectionLost() called.
> Disconnected
-----
Using Paho 1.2.0:
> 2018-07-27T14:57:55.701+00:00 vmr-133-17 event: CLIENT: CLIENT_CLIENT_CONNECT_MQTT: default #mqtt/JavaSample/11671 Client (971) #mqtt/JavaSample/11671 username default OriginalClientUsername(default) ClientId (JavaSample) connected to 192.168.133.17:1883 from 192.168.131.211:51875 SslVersion() SslCipher() authScheme(Basic) Clean(1) Will(0) SslRevocation(Not Checked)
ACTION (while application sleeping): Disconnect client from broker's perspective:
vmr-133-17(admin/client)# disconnect
Number of clients disconnected: 1.
> 2018-07-27T14:57:59.371+00:00 vmr-133-17 event: CLIENT: CLIENT_CLIENT_DISCONNECT_MQTT: default #mqtt/JavaSample/11671 Client (971) #mqtt/JavaSample/11671 username default ClientId (JavaSample) reason(Forced Logout) final statistics - dp(1, 1, 0, 0, 1, 1, 24, 4, 0, 0, 24, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) conn(0, 0, 192.168.131.211:51875, ESTAB, 0, 0, 0) mqtt(1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0), SslVersion(), SslCipher(), WillSent(0)
> 2018-07-27T14:57:59.374+00:00 vmr-133-17 event: CLIENT: CLIENT_CLIENT_CONNECT_MQTT: default #mqtt/JavaSample/11673 Client (972) #mqtt/JavaSample/11673 username default OriginalClientUsername(default) ClientId (JavaSample) connected to 192.168.133.17:1883 from 192.168.131.211:51876 SslVersion() SslCipher() authScheme(Basic) Clean(1) Will(0) SslRevocation(Not Checked)
> 2018-07-27T14:58:05.708+00:00 vmr-133-17 event: CLIENT: CLIENT_CLIENT_DISCONNECT_MQTT: default #mqtt/JavaSample/11673 Client (972) #mqtt/JavaSample/11673 username default ClientId (JavaSample) reason(Client Disconnect Received) final statistics - dp(2, 1, 0, 0, 2, 1, 26, 4, 0, 0, 26, 4, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0) conn(0, 0, 192.168.131.211:51876, ESTAB, 0, 0, 0) mqtt(1, 1, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 1), SslVersion(), SslCipher(), WillSent(0)
This results in InterruptedException being thrown on waitForCompletion():
> Connecting to broker: tcp://192.168.133.17:1883
> Connected
> connectionLost() called.
> reason 0
> msg MqttException
> loc MqttException
> cause java.lang.InterruptedException
> excep MqttException (0) - java.lang.InterruptedException
> MqttException (0) - java.lang.InterruptedException
> at org.eclipse.paho.client.mqttv3.internal.Token.waitForResponse(Token.java:148)
> at org.eclipse.paho.client.mqttv3.internal.Token.waitForCompletion(Token.java:108)
> at org.eclipse.paho.client.mqttv3.MqttToken.waitForCompletion(MqttToken.java:63)
> at PahoTest.PahoTest.App.MqttConnect(App.java:72)
> at PahoTest.PahoTest.App$1.connectionLost(App.java:49)
> at org.eclipse.paho.client.mqttv3.internal.CommsCallback.connectionLost(CommsCallback.java:292)
> at org.eclipse.paho.client.mqttv3.internal.ClientComms.shutdownConnection(ClientComms.java:423)
> at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:181)
> at java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
> at java.util.concurrent.FutureTask.run(Unknown Source)
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(Unknown Source)
> at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
> at java.lang.Thread.run(Unknown Source)
> Caused by: java.lang.InterruptedException
> at java.lang.Object.wait(Native Method)
> at java.lang.Object.wait(Unknown Source)
> at org.eclipse.paho.client.mqttv3.internal.Token.waitForResponse(Token.java:143)
> ... 14 more
> Disconnected
>
```
package PahoTest.PahoTest;
import org.eclipse.paho.client.mqttv3.IMqttAsyncClient;
import org.eclipse.paho.client.mqttv3.IMqttDeliveryToken;
import org.eclipse.paho.client.mqttv3.IMqttToken;
import org.eclipse.paho.client.mqttv3.MqttAsyncClient;
import org.eclipse.paho.client.mqttv3.MqttCallback;
import org.eclipse.paho.client.mqttv3.MqttConnectOptions;
import org.eclipse.paho.client.mqttv3.MqttException;
import org.eclipse.paho.client.mqttv3.MqttMessage;
import org.eclipse.paho.client.mqttv3.persist.MemoryPersistence;
public class App {
public static void main(String[] args) {
String broker = "tcp://192.168.133.17:1883";
String clientId = "JavaSample";
MemoryPersistence persistence = new MemoryPersistence();
try {
final IMqttAsyncClient sampleClient = new MqttAsyncClient(broker, clientId, persistence);
final MqttConnectOptions connOpts = new MqttConnectOptions();
connOpts.setCleanSession(true);
connOpts.setAutomaticReconnect(false);
System.out.println("Connecting to broker: " + broker);
MqttConnect(sampleClient, connOpts);
System.out.println("Connected");
sampleClient.setCallback(new MqttCallback() {
public void messageArrived(String arg0, MqttMessage arg1) throws Exception {
System.out.println("messageArrived() called.");
}
public void deliveryComplete(IMqttDeliveryToken arg0) {
System.out.println("deliveryComplete() called.");
}
public void connectionLost(Throwable arg0) {
System.out.println("connectionLost() called.");
MqttConnect(sampleClient, connOpts);
}
});
try {
Thread.sleep(10000);
} catch (InterruptedException e) {
// TODO Auto-generated catch block
e.printStackTrace();
}
sampleClient.disconnect();
System.out.println("Disconnected");
System.exit(0);
} catch (MqttException me) {
PrintMqttException(me);
}
}
public static void MqttConnect(IMqttAsyncClient client, MqttConnectOptions connOpts) {
try {
IMqttToken token = client.connect(connOpts);
token.waitForCompletion();
} catch (Exception e) {
PrintMqttException(e);
}
}
public static void PrintMqttException(Exception me) {
if (me instanceof MqttException) {
System.out.println("reason " + ((MqttException) me).getReasonCode());
}
System.out.println("msg " + me.getMessage());
System.out.println("loc " + me.getLocalizedMessage());
System.out.println("cause " + me.getCause());
System.out.println("excep " + me);
me.printStackTrace();
}
}
```
Contributor guide
Research direction
Start with the PahoTest.App MqttConnect call from connectionLost(), then read internal/Token.java and the stack-trace path through CommsCallback.java, ClientComms.java, and CommsReceiver.java. Reproduce the 1.2.0 behavior against the reported 1.1.0 behavior and verify that reconnecting from connectionLost() no longer produces InterruptedException from waitForCompletion().
Written by the indexing model from the issue text.
Assessment
- Tech stack
- java
- Domain
- networking
- Issue type
- Bug
- Difficulty
- 3/5
- Estimated time
- 1-2 days
- Activity status
- Stale
- Clarity
- Mostly clear
- Newbie friendliness
- 35/100