eclipse-paho / eclipse-paho/paho.mqtt.java
Websocket connection lost with mosquitto 1.6.15 and 2.0.11+
- 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!
- [x] Bug exists Release Version 1.2.5 ( Master Branch)
- [ ] Bug exists in MQTTv3 Client on Snapshot Version 1.2.6-SNAPSHOT (Develop Branch)
- [ ] Bug exists in MQTTv5 Client on Snapshot Version 1.2.6-SNAPSHOT (Develop Branch)
If this is a bug regarding the Android Service, please raise the bug here instead: https://github.com/eclipse/paho.mqtt.android/issues/new
---
ref: https://github.com/eclipse/mosquitto/issues/2631
[paho.mqtt.golang](https://github.com/eclipse/paho.mqtt.golang) does not terminate the connection, but **paho.mqtt.java** causes the websocket connection to terminate after 5 mins.
```java
MqttConnectOptions connectOptions = new MqttConnectOptions();
connectOptions.setCleanSession(true);
connectOptions.setUserName("username");
connectOptions.setPassword("password');
MqttClient mqttClient = new MqttClient("ws://localhost:9001", MqttClient.generateClientId());
IMqttToken iMqttToken = mqttClient.connectWithResult(connectOptions);
```
I used the default connection option, and the Mosquitto settings were configured and tested as follows.
```conf
persistence true
persistence_location /mosquitto/data/
log_dest file /mosquitto/log/mosquitto.log
port 1883
listener 9001
protocol websockets
allow_anonymous false
password_file /mosquitto/config/passwd
set_tcp_nodelay true
socket_domain ipv4
log_type all
websockets_log_level 8
```
The test result with docker-compose, issue occurs from 1.6.15 and 2.0.11+. ([Version 2.0.11 released](https://mosquitto.org/blog/2021/06/version-2-0-11-released/))
|JDK|Paho Java Client|Mosquitto|EOF|
|---|---|---|---|
|Temurin 11.0.16|1.2.5|2.0.15|💥|
|Temurin 11.0.16|1.2.5|2.0.14|💥|
|Temurin 11.0.16|1.2.5|2.0.13|💥|
|Temurin 11.0.16|1.2.5|2.0.12|💥|
|Temurin 11.0.16|1.2.5|2.0.11|💥|
|Temurin 11.0.16|1.2.5|2.0.10|OK|
|Temurin 11.0.16|1.2.5|2.0.9|OK|
|Temurin 11.0.16|1.2.5|1.6.15|💥|
|Temurin 11.0.16|1.2.5|1.6.14|OK|
|Temurin 11.0.16|1.2.5|1.6.9|OK|
Based on this result, I think there is a bug in the Paho Java Client library due to Mosquitto's changes.
More details
#### mosquitto.log
```shell
1662791998: mosquitto version 1.6.15 starting
1662791998: Config loaded from /mosquitto/config/mosquitto.conf.
1662791998: Opening websockets listen socket on port 9001.
1662791998: Opening ipv4 listen socket on port 1883.
1662791998: Opening ipv6 listen socket on port 1883.
1662791998: mosquitto version 1.6.15 running
1662792042: New client connected from 172.24.0.1 as paho1735120451144000 (p2, c1, k60, u'mambo').
1662792042: No will message specified.
1662792042: Sending CONNACK to paho1735120451144000 (0, 0)
1662792042: Received SUBSCRIBE from paho1735120451144000
1662792042: $SYS/broker/version (QoS 0)
1662792042: Sending PUBLISH to paho1735120451144000 (d0, q0, r1, m0, '$SYS/broker/version', ... (24 bytes))
1662792042: paho1735120451144000 0 $SYS/broker/version
1662792042: Sending SUBACK to paho1735120451144000
1662792042: Received SUBSCRIBE from paho1735120451144000
1662792042: test/# (QoS 0)
1662792042: paho1735120451144000 0 test/#
1662792042: Sending SUBACK to paho1735120451144000
1662792102: Received PINGREQ from paho1735120451144000
1662792102: Sending PINGRESP to paho1735120451144000
1662792162: Received PINGREQ from paho1735120451144000
1662792162: Sending PINGRESP to paho1735120451144000
1662792222: Received PINGREQ from paho1735120451144000
1662792222: Sending PINGRESP to paho1735120451144000
1662792282: Received PINGREQ from paho1735120451144000
1662792282: Sending PINGRESP to paho1735120451144000
1662792341: Socket error on client paho1735120451144000, disconnecting.
1662792842: mosquitto version 1.6.15 terminating
1662792842: Saving in-memory database to /mosquitto/data/mosquitto.db.
1662795072: mosquitto version 2.0.11 starting
1662795072: Config loaded from /mosquitto/config/mosquitto.conf.
1662795072: Opening websockets listen socket on port 9001.
1662795072: Opening ipv4 listen socket on port 1883.
1662795072: Opening ipv6 listen socket on port 1883.
1662795072: mosquitto version 2.0.11 running
1662795107: New client connected from 192.168.80.1:48834 as paho1738186178533400 (p2, c1, k60, u'mambo').
1662795107: No will message specified.
1662795107: Sending CONNACK to paho1738186178533400 (0, 0)
1662795107: Received SUBSCRIBE from paho1738186178533400
1662795107: $SYS/broker/version (QoS 0)
1662795107: paho1738186178533400 0 $SYS/broker/version
1662795107: Sending SUBACK to paho1738186178533400
1662795107: Sending PUBLISH to paho1738186178533400 (d0, q0, r1, m0, '$SYS/broker/version', ... (24 bytes))
1662795107: Received SUBSCRIBE from paho1738186178533400
1662795107: test/# (QoS 0)
1662795107: paho1738186178533400 0 test/#
1662795107: Sending SUBACK to paho1738186178533400
1662795167: Received PINGREQ from paho1738186178533400
1662795167: Sending PINGRESP to paho1738186178533400
1662795227: Received PINGREQ from paho1738186178533400
1662795227: Sending PINGRESP to paho1738186178533400
1662795287: Received PINGREQ from paho1738186178533400
1662795287: Sending PINGRESP to paho1738186178533400
1662795347: Received PINGREQ from paho1738186178533400
1662795347: Sending PINGRESP to paho1738186178533400
1662795407: Client paho1738186178533400 closed its connection.
1662795439: mosquitto version 2.0.11 terminating
1662795439: Saving in-memory database to /mosquitto/data//mosquitto.db.
```
#### Paho Java Client log
```shell
FINE: null: network read message
Sep 09, 2022 8:33:09 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver run
FINE: null: network read message
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver run
FINE: null: network read message
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver run
FINE: null: network read message
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver stop
FINE: null: stopping
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver stop
FINE: null: stopping
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver stop
FINE: null: stopped
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver stop
FINE: null: stopped
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsReceiver run
FINE: paho1622771147525800: Stopping due to IOException
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsReceiver run
FINE: paho1622771147525800: Stopping due to IOException
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientComms shutdownConnection
FINE: paho1622771147525800: state=DISCONNECTING
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientComms shutdownConnection
FINE: paho1622771147525800: state=DISCONNECTING
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsCallback stop
FINE: paho1622771147525800: stopping
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsCallback stop
FINE: paho1622771147525800: stopping
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsCallback stop
FINE: paho1622771147525800: notify workAvailable and wait for run
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsCallback stop
FINE: paho1622771147525800: notify workAvailable and wait for run
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsCallback stop
FINE: paho1622771147525800: stopped
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsCallback stop
FINE: paho1622771147525800: stopped
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsCallback run
FINE: paho1622771147525800: notify spaceAvailable
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsCallback run
FINE: paho1622771147525800: notify spaceAvailable
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsReceiver stop
FINE: paho1622771147525800: stopping
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsReceiver stop
FINE: paho1622771147525800: stopping
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsReceiver stop
FINE: paho1622771147525800: stopped
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsReceiver stop
FINE: paho1622771147525800: stopped
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver stop
FINE: null: stopping
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver stop
FINE: null: stopping
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver stop
FINE: null: stopped
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.websocket.WebSocketReceiver stop
FINE: null: stopped
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsTokenStore quiesce
FINE: paho1622771147525800: resp=Client is currently disconnecting (32102)
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsTokenStore quiesce
FINE: paho1622771147525800: resp=Client is currently disconnecting (32102)
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientComms handleOldTokens
FINE: paho1622771147525800: >
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientComms handleOldTokens
FINE: paho1622771147525800: >
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState resolveOldTokens
FINE: paho1622771147525800: reason Connection lost (32109) - java.io.EOFException
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState resolveOldTokens
FINE: paho1622771147525800: reason Connection lost (32109) - java.io.EOFException
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsTokenStore getOutstandingTokens
FINE: paho1622771147525800: >
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsTokenStore getOutstandingTokens
FINE: paho1622771147525800: >
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState disconnected
FINE: paho1622771147525800: disconnected
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState disconnected
FINE: paho1622771147525800: disconnected
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState clearState
FINE: paho1622771147525800: >
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState clearState
FINE: paho1622771147525800: >
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsTokenStore clear
FINE: paho1622771147525800: > 0 tokens
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsTokenStore clear
FINE: paho1622771147525800: > 0 tokens
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsSender stop
FINE: paho1622771147525800: stopping sender
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsSender stop
FINE: paho1622771147525800: stopping sender
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState notifyQueueLock
FINE: paho1622771147525800: notifying queueLock holders
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState notifyQueueLock
FINE: paho1622771147525800: notifying queueLock holders
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsSender stop
FINE: paho1622771147525800: stopped
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsSender stop
FINE: paho1622771147525800: stopped
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState get
FINE: paho1622771147525800: new work or ping arrived
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.TimerPingSender stop
FINE: paho1622771147525800: stop
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState get
FINE: paho1622771147525800: new work or ping arrived
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState get
FINE: paho1622771147525800: no outstanding flows and not connected
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientState get
FINE: paho1622771147525800: no outstanding flows and not connected
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.TimerPingSender stop
FINE: paho1622771147525800: stop
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsSender run
FINE: paho1622771147525800: get message returned null, stopping}
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsSender run
FINE: paho1622771147525800: get message returned null, stopping}
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsSender run
FINE: paho1622771147525800: <
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsSender run
FINE: paho1622771147525800: <
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientComms shutdownConnection
FINE: paho1622771147525800: state=DISCONNECTED
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.ClientComms shutdownConnection
FINE: paho1622771147525800: state=DISCONNECTED
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsCallback connectionLost
FINE: paho1622771147525800: call connectionLost
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsCallback connectionLost
FINE: paho1622771147525800: call connectionLost
Connection lost (32109) - java.io.EOFException
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:197)
at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.io.EOFException
at java.base/java.io.DataInputStream.readByte(DataInputStream.java:272)
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(MqttInputStream.java:92)
at org.eclipse.paho.client.mqttv3.internal.CommsReceiver.run(CommsReceiver.java:137)
... 1 more
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsReceiver run
FINE: paho1622771147525800: <
Sep 09, 2022 8:33:10 AM org.eclipse.paho.client.mqttv3.internal.CommsReceiver run
FINE: paho1622771147525800: <
```
Contributor guide
Assessment
This issue has not been assessed yet.