owntracks / quicksetup

A (mostly) automated installer for OwnTracks Recorder, Frontend with MQTT and Let's Encrypt
https://owntracks.org/booklet/guide/quicksetup/
12 stars 3 forks source link

Post quicksetup connection issues #41

Closed Ibexian closed 4 months ago

Ibexian commented 4 months ago

Hey 👋

I've gone through and followed the quicksetup booklet and run the .bootstrap, which resulted in no errors. All of the expected services are running (e.g. ot-recorder, mosquitto, nginx), the expected ports are open, and the server shows no obvious errors.

I've used the resulting front end to configure my android device (via either/both the URLconfig and OTRC file options), however it has been unable to connect. And I see no payloads when running mosquitto_sub -v -t '#'. While tailing the mosquitto logs shows only pings being sent and received to/from otrec.

Any suggestions/help would be much appreciated!

The app provides the following log output:

2024-05-23 12:49:42.710 D MessageProcessor: Initializing MessageProcessor
2024-05-23 12:49:42.711 D MessageProcessor: message:null, 
2024-05-23 12:49:42.712 D MessageProcessor: Reloading outgoing message processor. ThreadID: Thread[main,5,main]
2024-05-23 12:49:42.715 D MessageProcessor: Starting outbound message loop. ThreadID: Thread[backgroundDequeueThread,5,main]
2024-05-23 12:49:42.715 D Scheduler: WorkManager queue task PERIODIC_TASK_MQTT_RECONNECT as b82ec93f-788d-40d9-8195-3b1dcc6d9ba1
2024-05-23 12:49:42.720 D MessageProcessorEndpointMqtt: Sending message Thread: Thread[networkHandlerThread,5,main]
2024-05-23 12:49:42.722 D MessageProcessorEndpointMqtt: Connecting to broker. ThreadId: Thread[networkHandlerThread,5,main]
2024-05-23 12:49:42.722 D MessageProcessorEndpointMqtt: Connecting on non-ui worker thread: Thread[networkHandlerThread,5,main]
2024-05-23 12:49:42.723 D MessageProcessorEndpointMqtt: Acquired connecting lock
2024-05-23 12:49:42.724 D MessageProcessor: message:null, 
2024-05-23 12:49:42.725 D MessageProcessorEndpointMqtt: Initializing new mqttClient
2024-05-23 12:49:42.726 D MessageProcessorEndpointMqtt: 
2024-05-23 12:49:42.801 I MQTTReconnectWorker: MQTTReconnectWorker started on threadID: Thread[androidx.work-1,5,main]
2024-05-23 12:49:58.579 D MessageProcessorEndpointMqtt: Releasing connectinglock
2024-05-23 12:49:58.581 D MessageProcessor: message:MQTT Error: , 
2024-05-23 12:49:58.583 W MessageProcessorEndpointMqtt: failed connection attempts: 1
2024-05-23 12:49:58.585 E MessageProcessor: Message delivery failed. queueLength: 106, messageId: 1716464982095-550a5c
2024-05-23 12:49:58.587 D MessageProcessorEndpointMqtt: MQTT not current connecting
2024-05-23 12:49:58.588 W MessageProcessor: Error sending message. Re-queueing
2024-05-23 12:49:58.588 D MessageProcessorEndpointMqtt: Connecting to broker. ThreadId: Thread[networkHandlerThread,5,main]
2024-05-23 12:49:58.590 D MessageProcessorEndpointMqtt: Connecting on non-ui worker thread: Thread[networkHandlerThread,5,main]
2024-05-23 12:49:58.590 D MessageProcessorEndpointMqtt: Acquired connecting lock
2024-05-23 12:49:58.592 D MessageProcessor: message:null, 
2024-05-23 12:49:58.593 D MessageProcessorEndpointMqtt: Disconnecting mqtt Client
2024-05-23 12:49:58.596 I MessageProcessor: Waiting for 1 s before retrying
2024-05-23 12:49:58.596 D MessageProcessorEndpointMqtt: Error disconnecting from mqtt client.
 (32101)
    at okio.Okio__OkioKt.createMqttException(Unknown Source:9)
    at org.eclipse.paho.client.mqttv3.internal.ClientComms.disconnect(SourceFile:113)
    at org.eclipse.paho.client.mqttv3.MqttAsyncClient.disconnect(SourceFile:51)
    at org.owntracks.android.services.MessageProcessorEndpointMqtt.connectToBroker(SourceFile:135)
    at org.owntracks.android.services.MessageProcessorEndpointMqtt.reconnect(SourceFile:46)
    at org.owntracks.android.services.MessageProcessorEndpointMqtt.lambda$reconnect$1(Unknown Source:0)
    at org.owntracks.android.services.MessageProcessorEndpointMqtt.$r8$lambda$3UR4gQL2b_UbF_ekJLIMhafolpU(Unknown Source:0)
    at org.owntracks.android.services.MessageProcessorEndpointMqtt$$ExternalSyntheticLambda0.run(Unknown Source:18)
    at android.os.Handler.handleCallback(Handler.java:942)
    at android.os.Handler.dispatchMessage(Handler.java:99)
    at android.os.Looper.loopOnce(Looper.java:201)
    at android.os.Looper.loop(Looper.java:288)
    at android.os.HandlerThread.run(HandlerThread.java:67)

2024-05-23 12:49:58.597 D MessageProcessorEndpointMqtt: Initializing new mqttClient
2024-05-23 12:49:58.598 D MessageProcessorEndpointMqtt: 
2024-05-23 12:50:14.474 D MessageProcessorEndpointMqtt: Releasing connectinglock
2024-05-23 12:50:14.476 D MessageProcessor: message:MQTT Error: , 
2024-05-23 12:50:14.479 E MessageProcessorEndpointMqtt: Failed to reconnect to MQTT broker
org.owntracks.android.services.MqttConnectionException:  (0) - java.net.SocketException: Connection reset
    at org.owntracks.android.services.MessageProcessorEndpointMqtt.connectToBroker(SourceFile:243)
    at org.owntracks.android.services.MessageProcessorEndpointMqtt.reconnect(SourceFile:46)
    at org.owntracks.android.services.MessageProcessorEndpointMqtt.lambda$reconnect$1(Unknown Source:0)
    at org.owntracks.android.services.MessageProcessorEndpointMqtt.$r8$lambda$3UR4gQL2b_UbF_ekJLIMhafolpU(Unknown Source:0)
    at org.owntracks.android.services.MessageProcessorEndpointMqtt$$ExternalSyntheticLambda0.run(Unknown Source:18)
    at android.os.Handler.handleCallback(Handler.java:942)
    at android.os.Handler.dispatchMessage(Handler.java:99)
    at android.os.Looper.loopOnce(Looper.java:201)
    at android.os.Looper.loop(Looper.java:288)
    at android.os.HandlerThread.run(HandlerThread.java:67)
Caused by:  (0) - java.net.SocketException: Connection reset
    at androidx.work.impl.utils.WorkForegroundUpdater$1.run(SourceFile:433)
    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(Unknown Source:24)
    at org.conscrypt.ConscryptEngineSocket$SSLInputStream.processDataFromSocket(SourceFile:172)
    at org.conscrypt.ConscryptEngineSocket$SSLInputStream.access$100(Unknown Source:0)
    at org.conscrypt.ConscryptEngineSocket.doHandshake(Unknown Source:90)
    at org.conscrypt.ConscryptEngineSocket.startHandshake(Unknown Source:36)
    at org.eclipse.paho.client.mqttv3.internal.SSLNetworkModule.start(Unknown Source:83)
    at androidx.work.impl.utils.WorkForegroundUpdater$1.run(SourceFile:174)
    ... 1 more
Ibexian commented 4 months ago

Ah, it was something to do with the cloudflare proxy - disabling fixed the issue.

jpmens commented 4 months ago

Glad you got it working