You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
I'm experiencing an issue since several months where OwnTracks seems to disconnect from my MQTT broker (Mosquitto), and does not automatically reconnect at all. This causes the endpoint queue to fill up. Manually going to connection settings and tapping the reconnect button seems to resolve the issue, but it always re-occurs after a few days.
I'm connecting to my MQTT broker using a self-signed certificate. As you can see in the provided screenshots, I've correctly enabled precise background location and whitelisted the app from battery optimization.
I am aware that this issue seems similar to #1898, but it appears that the queue doesn't fill up for them as it does for me. Therefore I've created this separate issue.
This seems to be the interesting part of the logs:
2024-09-15 15:01:08.785 I [DefaultDispatcher-worker-8] MQTTReconnectWorker: MQTT reconnect worker job started
2024-09-15 15:01:09.246 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$connectToBroker: Connecting to ssl://mqtt.server.tld:8883?# timeout = 30s
2024-09-15 15:01:09.850 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$connectToBroker: MQTT Connected. Subscribing to [owntracks/+/+, owntracks/+/+/event, owntracks/+/+/info, owntracks/+/+/status, owntracks/user1/dm3q/cmd]
2024-09-15 15:01:09.860 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$connectToBroker: MQTT Subscribed
2024-09-15 15:01:09.874 I [DefaultDispatcher-worker-8] MQTTReconnectWorker: MQTT reconnect worker job completed, status Success {mOutputData=Data {}}
2024-09-15 15:01:09.875 I [DefaultDispatcher-worker-7] MQTTMessageProcessorEndpoint: Sending message [MessageLocation id=46bcaeb8 ts=2024-09-15T10:25:44Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:01:09.868Z,trigger=DEFAULT]
2024-09-15 15:01:09.884 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$sendMessage$2$1$job: Message [MessageLocation id=46bcaeb8 ts=2024-09-15T10:25:44Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:01:09.868Z,trigger=DEFAULT] dispatched in 7.708594ms
2024-09-15 15:01:09.897 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=1e1d51fa
2024-09-15 15:01:09.899 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user2/phone with id=1a243bf0
2024-09-15 15:01:09.906 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=46bcaeb8
2024-09-15 15:09:10.340 E [MQTT Rec: mys23ultra] MQTTMessageProcessorEndpoint$mqttCallback: Connection Lost
Connection lost (32109) - java.net.SocketException: Connection reset
at org.eclipse.paho.client.mqttv3.internal.CommsSender.run(SourceFile:261)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
at java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:307)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
at java.lang.Thread.run(Thread.java:1012)
Caused by: java.net.SocketException: Connection reset
at java.net.SocketInputStream.read(SocketInputStream.java:191)
at java.net.SocketInputStream.read(SocketInputStream.java:143)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.readFromSocket(SourceFile:25)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.processDataFromSocket(SourceFile:173)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.readUntilDataAvailable(SourceFile:1)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(SourceFile:14)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(SourceFile:3)
at java.io.DataInputStream.readByte(DataInputStream.java:273)
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(SourceFile:14)
at org.eclipse.paho.client.mqttv3.internal.CommsSender.run(SourceFile:88)
... 6 more
2024-09-15 15:09:20.383 I [DefaultDispatcher-worker-8] MQTTReconnectWorker: MQTT reconnect worker job started
2024-09-15 15:09:21.034 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$connectToBroker: Connecting to ssl://mqtt.server.tld:8883?# timeout = 30s
2024-09-15 15:09:21.837 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$connectToBroker: MQTT Connected. Subscribing to [owntracks/+/+, owntracks/+/+/event, owntracks/+/+/info, owntracks/+/+/status, owntracks/user1/dm3q/cmd]
2024-09-15 15:09:21.865 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$connectToBroker: MQTT Subscribed
2024-09-15 15:09:21.890 I [DefaultDispatcher-worker-8] MQTTReconnectWorker: MQTT reconnect worker job completed, status Success {mOutputData=Data {}}
2024-09-15 15:09:21.890 I [DefaultDispatcher-worker-7] MQTTMessageProcessorEndpoint: Sending message [MessageLocation id=6823a20d ts=2024-09-15T10:25:44Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:09:21.878Z,trigger=DEFAULT]
2024-09-15 15:09:21.901 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$sendMessage$2$1$job: Message [MessageLocation id=6823a20d ts=2024-09-15T10:25:44Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:09:21.878Z,trigger=DEFAULT] dispatched in 9.030260ms
2024-09-15 15:09:21.938 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=46bcaeb8
2024-09-15 15:09:21.941 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user2/phone with id=c1a79a4b
2024-09-15 15:09:21.968 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=6823a20d
2024-09-15 15:10:38.187 I [main] PreferencesStore: Setting default preference value for locatorPriority to null
2024-09-15 15:10:38.237 I [DefaultDispatcher-worker-7] MQTTMessageProcessorEndpoint: Sending message [MessageLocation id=b63f9c96 ts=2024-09-15T13:09:14Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:10:38.228Z,trigger=DEFAULT]
2024-09-15 15:10:38.249 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$sendMessage$2$1$job: Message [MessageLocation id=b63f9c96 ts=2024-09-15T13:09:14Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:10:38.228Z,trigger=DEFAULT] dispatched in 9.364271ms
2024-09-15 15:10:38.287 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=b63f9c96
2024-09-15 15:10:38.306 I [DefaultDispatcher-worker-7] MQTTMessageProcessorEndpoint: Sending message [MessageLocation id=219df064 ts=2024-09-15T13:09:14Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:10:38.280Z,trigger=PING]
2024-09-15 15:10:38.307 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$sendMessage$2$1$job: Message [MessageLocation id=219df064 ts=2024-09-15T13:09:14Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:10:38.280Z,trigger=PING] dispatched in 1.149687ms
2024-09-15 15:10:38.308 I [DefaultDispatcher-worker-7] MQTTMessageProcessorEndpoint: Sending message [MessageLocation id=9bd9fddc ts=2024-09-15T13:09:46Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:10:38.307Z,trigger=DEFAULT]
2024-09-15 15:10:38.322 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$sendMessage$2$1$job: Message [MessageLocation id=9bd9fddc ts=2024-09-15T13:09:46Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:10:38.307Z,trigger=DEFAULT] dispatched in 12.909532ms
2024-09-15 15:10:38.323 I [DefaultDispatcher-worker-7] MQTTMessageProcessorEndpoint: Sending message [MessageTransition ts=2024-09-15T13:09:46Z,event=leave,desc=Home,lon=5.0521786,lat=REDACTED,acc=4,trigger=l,trackerId=3q]
2024-09-15 15:10:38.339 I [DefaultDispatcher-worker-8] MQTTMessageProcessorEndpoint$sendMessage$2$1$job: Message [MessageTransition ts=2024-09-15T13:09:46Z,event=leave,desc=Home,lon=5.0521786,lat=REDACTED,acc=4,trigger=l,trackerId=3q] dispatched in 9.556979ms
2024-09-15 15:10:38.354 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=219df064
2024-09-15 15:10:38.413 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=9bd9fddc
2024-09-15 15:10:38.464 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageTransition on owntracks/user1/dm3q/event with id=3d59c2f6
2024-09-15 15:10:39.597 I [DefaultDispatcher-worker-7] MQTTMessageProcessorEndpoint: Sending message [MessageLocation id=fe7563ab ts=2024-09-15T13:10:39Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:10:39.593Z,trigger=DEFAULT]
2024-09-15 15:10:39.600 I [DefaultDispatcher-worker-2] MQTTMessageProcessorEndpoint$sendMessage$2$1$job: Message [MessageLocation id=fe7563ab ts=2024-09-15T13:10:39Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:10:39.593Z,trigger=DEFAULT] dispatched in 1.658906ms
2024-09-15 15:10:39.641 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=fe7563ab
2024-09-15 15:10:57.705 E [MQTT Rec: mys23ultra] MQTTMessageProcessorEndpoint$mqttCallback: Connection Lost
Connection lost (32109) - java.net.SocketException: Software caused connection abort
at org.eclipse.paho.client.mqttv3.internal.CommsSender.run(SourceFile:261)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
at java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:307)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
at java.lang.Thread.run(Thread.java:1012)
Caused by: java.net.SocketException: Software caused connection abort
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:118)
at java.net.SocketInputStream.read(SocketInputStream.java:173)
at java.net.SocketInputStream.read(SocketInputStream.java:143)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.readFromSocket(SourceFile:25)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.processDataFromSocket(SourceFile:173)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.readUntilDataAvailable(SourceFile:1)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(SourceFile:14)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(SourceFile:3)
at java.io.DataInputStream.readByte(DataInputStream.java:273)
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(SourceFile:14)
at org.eclipse.paho.client.mqttv3.internal.CommsSender.run(SourceFile:88)
... 6 more
2024-09-15 15:10:58.807 I [DefaultDispatcher-worker-2] MQTTMessageProcessorEndpoint$connectToBroker: Connecting to ssl://mqtt.server.tld:8883?# timeout = 30s
2024-09-15 15:10:59.541 I [DefaultDispatcher-worker-2] MQTTMessageProcessorEndpoint$connectToBroker: MQTT Connected. Subscribing to [owntracks/+/+, owntracks/+/+/event, owntracks/+/+/info, owntracks/+/+/status, owntracks/user1/dm3q/cmd]
2024-09-15 15:10:59.563 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLwt on owntracks/user1/dm3q with id=0
2024-09-15 15:10:59.620 I [DefaultDispatcher-worker-2] MQTTMessageProcessorEndpoint$connectToBroker: MQTT Subscribed
2024-09-15 15:10:59.628 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=fe7563ab
2024-09-15 15:10:59.631 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user2/phone with id=16de99fe
2024-09-15 15:10:59.635 I [DefaultDispatcher-worker-7] MQTTMessageProcessorEndpoint: Sending message [MessageLocation id=11da8249 ts=2024-09-15T13:10:39Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:10:59.627Z,trigger=DEFAULT]
2024-09-15 15:10:59.644 I [DefaultDispatcher-worker-1] MQTTMessageProcessorEndpoint$sendMessage$2$1$job: Message [MessageLocation id=11da8249 ts=2024-09-15T13:10:39Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:10:59.627Z,trigger=DEFAULT] dispatched in 7.900625ms
2024-09-15 15:10:59.687 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=11da8249
2024-09-15 15:11:40.708 E [MQTT Rec: mys23ultra] MQTTMessageProcessorEndpoint$mqttCallback: Connection Lost
Connection lost (32109) - java.net.SocketException: Software caused connection abort
at org.eclipse.paho.client.mqttv3.internal.CommsSender.run(SourceFile:261)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
at java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:307)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
at java.lang.Thread.run(Thread.java:1012)
Caused by: java.net.SocketException: Software caused connection abort
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:118)
at java.net.SocketInputStream.read(SocketInputStream.java:173)
at java.net.SocketInputStream.read(SocketInputStream.java:143)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.readFromSocket(SourceFile:25)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.processDataFromSocket(SourceFile:173)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.readUntilDataAvailable(SourceFile:1)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(SourceFile:14)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(SourceFile:3)
at java.io.DataInputStream.readByte(DataInputStream.java:273)
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(SourceFile:14)
at org.eclipse.paho.client.mqttv3.internal.CommsSender.run(SourceFile:88)
... 6 more
2024-09-15 15:11:41.174 I [DefaultDispatcher-worker-5] MQTTMessageProcessorEndpoint$connectToBroker: Connecting to ssl://mqtt.server.tld:8883?# timeout = 30s
2024-09-15 15:11:41.844 I [DefaultDispatcher-worker-5] MQTTMessageProcessorEndpoint$connectToBroker: MQTT Connected. Subscribing to [owntracks/+/+, owntracks/+/+/event, owntracks/+/+/info, owntracks/+/+/status, owntracks/user1/dm3q/cmd]
2024-09-15 15:11:41.851 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLwt on owntracks/user1/dm3q with id=0
2024-09-15 15:11:41.918 I [DefaultDispatcher-worker-5] MQTTMessageProcessorEndpoint$connectToBroker: MQTT Subscribed
2024-09-15 15:11:41.921 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=11da8249
2024-09-15 15:11:41.926 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user2/phone with id=48300b4d
2024-09-15 15:11:41.937 I [DefaultDispatcher-worker-7] MQTTMessageProcessorEndpoint: Sending message [MessageLocation id=cd7c7059 ts=2024-09-15T13:10:39Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:11:41.929Z,trigger=DEFAULT]
2024-09-15 15:11:41.946 I [DefaultDispatcher-worker-1] MQTTMessageProcessorEndpoint$sendMessage$2$1$job: Message [MessageLocation id=cd7c7059 ts=2024-09-15T13:10:39Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:11:41.929Z,trigger=DEFAULT] dispatched in 7.520833ms
2024-09-15 15:11:42.039 I [MQTT Call: mys23ultra] MessageProcessor: Received incoming message: MessageLocation on owntracks/user1/dm3q with id=cd7c7059
2024-09-15 15:11:42.613 E [MQTT Rec: mys23ultra] MQTTMessageProcessorEndpoint$mqttCallback: Connection Lost
Connection lost (32109) - java.net.SocketException: Software caused connection abort
at org.eclipse.paho.client.mqttv3.internal.CommsSender.run(SourceFile:261)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:487)
at java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:307)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:644)
at java.lang.Thread.run(Thread.java:1012)
Caused by: java.net.SocketException: Software caused connection abort
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:118)
at java.net.SocketInputStream.read(SocketInputStream.java:173)
at java.net.SocketInputStream.read(SocketInputStream.java:143)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.readFromSocket(SourceFile:25)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.processDataFromSocket(SourceFile:173)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.readUntilDataAvailable(SourceFile:1)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(SourceFile:14)
at org.conscrypt.ConscryptEngineSocket$SSLInputStream.read(SourceFile:3)
at java.io.DataInputStream.readByte(DataInputStream.java:273)
at org.eclipse.paho.client.mqttv3.internal.wire.MqttInputStream.readMqttWireMessage(SourceFile:14)
at org.eclipse.paho.client.mqttv3.internal.CommsSender.run(SourceFile:88)
... 6 more
2024-09-15 15:11:43.005 I [DefaultDispatcher-worker-1] MQTTMessageProcessorEndpoint$connectToBroker: Connecting to ssl://mqtt.server.tld:8883?# timeout = 30s
2024-09-15 15:11:45.733 I [DefaultDispatcher-worker-7] MQTTMessageProcessorEndpoint: Sending message [MessageLocation id=20d37349 ts=2024-09-15T13:11:45Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:11:45.723Z,trigger=DEFAULT]
2024-09-15 15:11:45.733 W [DefaultDispatcher-worker-7] MessageProcessor: Error sending message [MessageLocation id=20d37349 ts=2024-09-15T13:11:45Z,lat=REDACTED,long=REDACTED,created_at=2024-09-15T13:11:45.723Z,trigger=DEFAULT]. Re-queueing
org.owntracks.android.net.mqtt.MQTTMessageProcessorEndpoint$NotConnectedException
at org.owntracks.android.net.mqtt.MQTTMessageProcessorEndpoint.sendMessage-gIAlu-s(SourceFile:55)
at org.owntracks.android.services.MessageProcessor.sendAvailableMessages(SourceFile:640)
at org.owntracks.android.services.MessageProcessor.access$sendAvailableMessages(SourceFile:1)
at org.owntracks.android.services.MessageProcessor$sendAvailableMessages$1.invokeSuspend(Unknown Source:11)
at kotlin.coroutines.jvm.internal.ContinuationImpl.resumeWith(SourceFile:9)
at kotlinx.coroutines.DispatchedTask.run(SourceFile:115)
at androidx.work.Worker$2.run(SourceFile:148)
at kotlinx.coroutines.scheduling.TaskImpl.run(SourceFile:3)
at kotlinx.coroutines.scheduling.CoroutineScheduler$Worker.run(SourceFile:96)
The text was updated successfully, but these errors were encountered:
I'm experiencing an issue since several months where OwnTracks seems to disconnect from my MQTT broker (Mosquitto), and does not automatically reconnect at all. This causes the endpoint queue to fill up. Manually going to connection settings and tapping the reconnect button seems to resolve the issue, but it always re-occurs after a few days.
I'm connecting to my MQTT broker using a self-signed certificate. As you can see in the provided screenshots, I've correctly enabled precise background location and whitelisted the app from battery optimization.
I am aware that this issue seems similar to #1898, but it appears that the queue doesn't fill up for them as it does for me. Therefore I've created this separate issue.
I have included the logs and a status screenshot:
2024-09-16 OwnTracks.log
This seems to be the interesting part of the logs:
The text was updated successfully, but these errors were encountered: