When SSL is enabled automatic reconnects fail

[haydster7]

I have been experiencing an issue with reconnects.

After a disconnect (presumably from network change or timeout or various other reasons as mentioned in #19 ) the client fails automatic reconnect attempts.

The only way I am able to reconnect after these disconnects is to go into the broker settings, change a setting (anything, doesn't matter, just refreshes the broker and forces something?). Then I change the setting back to the correct ones, and reconnect is then successful.

I can provide logs if needed, not sure how to grab them though.

[deepessh]

Hey, does the app crash? Or does it just not reconnect.

Also, can you share your tasker and broker config?

[haydster7]

Since reporting this I've had a hard time replicating it reliably. It normally occurs after a long time not using it (for example at work for the day), then trying it again in the afternoon and it won't work without manual intervention. I also noticed some strange errors in the mosquitto logs after reviewing, not sure on what times they line up to yet, and not sure if this failed to reconnect happens when not using SSL.

Give me a few more days of use where Im away from the network and MQTT Client is dormant for long periods of time, and I'll report back with additional observations.

Tasker I have one receive event. This runs a task that either changes a global variable to on or off based on the mqtt client variable.

I have one task that I run from a widget, which sends either on or off to my switch.

MQTT Client App settings: Persistent notifications: YES

Broker settings: Enabled: YES Use Websockets: NO Use MQTT v3.1: YES

The other broker settings have been changing as I've been experimenting between local/remote and ssl/tcp. Will stick with remote SSL for now while I try to replicate.

[haydster7]

It turns out the only way to replicate this is to first force issue #19 (frequent disconnects). I found a way to do this which is to force stop the client app. Expected behaviour would be once a tasker task is launched, or the app is manually restarted, mqtt will re-connect. Unfortunately when upon restart any connection attempt fails if using SSL.

I have found that changing the broker settings is not actually what solves the issue. Pressing the save button (even when settings are the same) on the broker settings will initiate a successful reconnect. The automatic reconnects though will always fail.

Here is my mosquitto log with the actions I was performing in the MQTT client using SSL.

Here is my mosquitto log with the actions I was performing in the MQTT client without SSL.

So it looks like this could actually be an SSL issue. The connection works fine though when pressing the save button, so maybe automatic reconnects aren't triggering the same way as a manual reconnect.

[deepessh]

Hey thanks for the mosquitto log. It helps a lot. Let me debug more on the issue.

[deepessh]

Are you using self signed certificate?

[haydster7]

Yes, I created the cert myself. Strange that it works fine on manual connect though

[deepessh]

Hey are you using client certificate for authentication as well? Can you share your config file (remove your personal details)?

[haydster7]

Sure thing. require_certificate is set to false. Mosquitto default conf file:

pid_file /var/run/mosquitto.pid

persistence true
persistence_location /var/lib/mosquitto/

log_dest file /var/log/mosquitto/mosquitto.log

include_dir /etc/mosquitto/conf.d

Mosquitto custom override conf:

#User authentication

allow_anonymous false
password_file /etc/mosquitto/passwd

#SSL/TLS
port 8883
cafile /etc/mosquitto/cert/mqtt_ca.crt
certfile /etc/mosquitto/cert/mqtt_server_noenc.crt
keyfile /etc/mosquitto/cert/mqtt_server_noenc.key
require_certificate false
tls_version tlsv1.1

[deepessh]

Hey, so, apparently, I am not able to simulate the issue on Android 7.1. Which version of android are you using?

[haydster7]

Android 8.0.0 on pixel 1 xl I have Android studio but have only about 10% idea on how to use it.

I can try a Dev apk if you've got any ideas.

I feel like the auto reconnect functionality is for some reason not calling the full connect method or SSL method how the save button does.

[deepessh]

I feel like the auto reconnect functionality is for some reason not calling the full connect method or SSL method how the save button does.

Yeah, right. But it is not supposed to call the full connect method again. The reconnect is handled by Paho MQTT library.

Can you use adb to share the logcat for the time the app fails to reconnect?

[deepessh]

Also, how did you generate your SSL certificates?

[haydster7]

Can post the entire log if necessary, I think this is the bit you're looking for. Errors directly after launching due to ssl

12-20 19:23:12.049  1103 10183 I ActivityManager: Start proc 31366:in.dc297.mqttclpro/u0a275 for activity in.dc297.mqttclpro/.activity.BrokersListActivity
12-20 19:23:12.307 31366 31366 I in.dc297.mqttclpro.services.MyMqttService: Creating service
12-20 19:23:12.307 31366 31366 I in.dc297.mqttclpro.services.MyMqttService: Starting service
12-20 19:23:12.308 31366 31366 I in.dc297.mqttclpro.mqtt.internal.MQTTClients: creating new instance
12-20 19:23:12.377 31366 31366 W System.err:    at in.dc297.mqttclpro.SSL.SSLUtil.getSocketFactory(SSLUtil.java:87)
12-20 19:23:12.377 31366 31366 W System.err:    at in.dc297.mqttclpro.mqtt.internal.MQTTClients.fromEntity(MQTTClients.java:293)
12-20 19:23:12.377 31366 31366 W System.err:    at in.dc297.mqttclpro.mqtt.internal.MQTTClients.<init>(MQTTClients.java:87)
12-20 19:23:12.377 31366 31366 W System.err:    at in.dc297.mqttclpro.mqtt.internal.MQTTClients.getInstance(MQTTClients.java:97)
12-20 19:23:12.377 31366 31366 W System.err:    at in.dc297.mqttclpro.services.MyMqttService.onStartCommand(MyMqttService.java:34)
12-20 19:23:12.529  1103  1152 I ActivityManager: Displayed in.dc297.mqttclpro/.activity.BrokersListActivity: +489ms
12-20 19:23:13.902  1103  2706 I ActivityManager: START u0 {cmp=in.dc297.mqttclpro/.activity.SubscribedTopicsActivity (has extras)} from uid 10275
12-20 19:23:13.959 31366 31366 I in.dc297.mqttclpro.activity.SubscribedTopicsActivity: 2

I was also able to continually force the error after that by calling the publish from tasker

12-20 19:23:19.644 31411 31411 I in.dc297.mqttclpro.tasker.receivers.FireReceiver: Received fire from tasker in.dc297.mqttclpro.tasker.activity.Intent.MQTT_PUBLISH_ACTION
12-20 19:23:19.703 31366 31426 W System.err:    at in.dc297.mqttclpro.SSL.SSLUtil.getSocketFactory(SSLUtil.java:87)
12-20 19:23:19.703 31366 31426 W System.err:    at in.dc297.mqttclpro.mqtt.internal.MQTTClients.fromEntity(MQTTClients.java:293)
12-20 19:23:19.703 31366 31426 W System.err:    at in.dc297.mqttclpro.mqtt.internal.MQTTClients.doConnect(MQTTClients.java:541)
12-20 19:23:19.703 31366 31426 W System.err:    at in.dc297.mqttclpro.tasker.services.MyIntentService$2.accept(MyIntentService.java:142)
12-20 19:23:19.703 31366 31426 W System.err:    at in.dc297.mqttclpro.tasker.services.MyIntentService$2.accept(MyIntentService.java:135)
12-20 19:23:19.704 31366 31426 W System.err:    at in.dc297.mqttclpro.tasker.services.MyIntentService.startConnectAction(MyIntentService.java:135)
12-20 19:23:19.704 31366 31426 W System.err:    at in.dc297.mqttclpro.tasker.services.MyIntentService.onHandleIntent(MyIntentService.java:161)

I generated the SSL cert on the raspberry pi using openssl

[deepessh]

That's really helpful. I think I know what the issue might be. I'll push an update to play store soon.

Cheers!

[deepessh]

Just uploaded a new version 4.4.2. Check if it fixes the issue for you.

[haydster7]

Beautiful, beautiful, beautiful work. Just ran adb logcat in.dc297.mqttclpro*:V System.err:V *:S and got nothing in response, nice work.

I did a force stop and a restart and it instantly reconnects for tasker commands :)