After Mosquitto update increased connection time

Hi all,

two days ago i updated my Mosquitto in my home assistant instance (as well as HA to 0.92) I was running some version pre 4.1 and now i am running version 4.2 according to home assistant.

I have had my weather station and other small temperature recorder (based on a ESP8266, connecting through mqtt) running for months now, so i did not change anything, only upgrading mosquitto and home assistant. Before, i had a total connection time of about 4500ms from startup of my esp8266 to right before publishing. As of yesterday, with that Mosquitto upgrade my connection times increased dramatically.

I debugged my sketch and found that connecting to my mqtt broker takes about 3500ms. Publishing <30ms, no problem here. I started to tinker around in my sketch, nothing helped. Keepalive connection parameters won’t help me, as i put my ESP8266 in deepsleep. So WiFi and MQTT will be connected upon every time the device restarts.

In the mosquitto logs you can clearly see that it takes about 3 seconds until my devices has connected and published and disconnected. Attached are the logs.
I added access control lists like suggested in the help page. This did not help though. It takes solid 3 seconds every time a device connects.

Since these 3 seconds are extremely valuable in terms of battery life, i want this issue resolved badly. Can you help me with that?

Thanks

{
“logins”: [
{
“username”: “xxx”,
“password”: “xxx”
},
{
“username”: “iot”,
“password”: “xxx”
}
],
“anonymous”: false,
“quiet_logs”: false,
“customize”: {
“active”: true,
“folder”: “mosquitto”
},
“certfile”: “fullchain.pem”,
“keyfile”: “privkey.pem”
}

1556468733: New connection from 10.10.10.30 on port 1883.
1556468733: |-- mosquitto_auth_unpwd_check(iot)
1556468733: |-- ** checking backend http
1556468733: |-- url=http://127.0.0.1:8080/login
1556468733: |-- data=username=iot&password=xxxxxx&topic=&acc=-1&clientid=
[INFO] found iot on local database
1556468736: |-- getuser(iot) AUTHENTICATED=1 by http
1556468736: New client connected from 10.10.10.30 as kuchenbox (c1, k15, u’iot’).
1556468736: Client kuchenbox disconnected.
1556468823: New connection from 10.10.10.33 on port 1883.
1556468823: |-- mosquitto_auth_unpwd_check(iot)
1556468823: |-- ** checking backend http
1556468823: |-- url=http://127.0.0.1:8080/login
1556468823: |-- data=username=iot&password=xxxxxx&topic=&acc=-1&clientid=
[INFO] found iot on local database
1556468826: |-- getuser(iot) AUTHENTICATED=1 by http
1556468826: New client connected from 10.10.10.33 as Neon (c1, k15, u’iot’).
1556468826: Client Neon disconnected.
1556468870: New connection from 10.10.10.32 on port 1883.
1556468870: |-- mosquitto_auth_unpwd_check(iot)
1556468870: |-- ** checking backend http
1556468870: |-- url=http://127.0.0.1:8080/login
1556468870: |-- data=username=iot&password=xxxxxx&topic=&acc=-1&clientid=
[INFO] found iot on local database
1556468872: |-- getuser(iot) AUTHENTICATED=1 by http
1556468872: New client connected from 10.10.10.32 as Io (c1, k15, u’iot’).
1556468873: Client Io disconnected.
1556468967: New connection from 10.10.10.30 on port 1883.
1556468967: |-- mosquitto_auth_unpwd_check(iot)
1556468967: |-- ** checking backend http
1556468967: |-- url=http://127.0.0.1:8080/login
1556468967: |-- data=username=iot&password=xxxxxx&topic=&acc=-1&clientid=
[INFO] found iot on local database
1556468970: |-- getuser(iot) AUTHENTICATED=1 by http
1556468970: New client connected from 10.10.10.30 as kuchenbox (c1, k15, u’iot’).
1556468993: Client kuchenbox has exceeded timeout, disconnecting.
1556468993: Socket error on client kuchenbox, disconnecting.
1556469203: New connection from 10.10.10.30 on port 1883.
1556469203: |-- mosquitto_auth_unpwd_check(iot)
1556469203: |-- ** checking backend http
1556469203: |-- url=http://127.0.0.1:8080/login
1556469203: |-- data=username=iot&password=xxxxxx&topic=&acc=-1&clientid=
[INFO] found iot on local database
1556469205: |-- getuser(iot) AUTHENTICATED=1 by http
1556469205: New client connected from 10.10.10.30 as kuchenbox (c1, k15, u’iot’).
1556469228: Client kuchenbox has exceeded timeout, disconnecting.
1556469228: Socket error on client kuchenbox, disconnecting.
1556469438: New connection from 10.10.10.30 on port 1883.
1556469438: |-- mosquitto_auth_unpwd_check(iot)
1556469438: |-- ** checking backend http
1556469438: |-- url=http://127.0.0.1:8080/login
1556469438: |-- data=username=iot&password=xxxxxx&topic=&acc=-1&clientid=
[INFO] found iot on local database
1556469441: |-- getuser(iot) AUTHENTICATED=1 by http
1556469441: New client connected from 10.10.10.30 as kuchenbox (c1, k15, u’iot’).
1556469464: Client kuchenbox has exceeded timeout, disconnecting.
1556469464: Socket error on client kuchenbox, disconnecting.
1556469508: New connection from 10.10.10.33 on port 1883.
1556469508: |-- mosquitto_auth_unpwd_check(iot)
1556469508: |-- ** checking backend http
1556469508: |-- url=http://127.0.0.1:8080/login
1556469508: |-- data=username=iot&password=xxxxxx&topic=&acc=-1&clientid=
[INFO] found iot on local database
1556469511: |-- getuser(iot) AUTHENTICATED=1 by http
1556469511: New client connected from 10.10.10.33 as Neon (c1, k15, u’iot’).
1556469511: Client Neon disconnected.
1556469547: New connection from 10.10.10.32 on port 1883.
1556469547: |-- mosquitto_auth_unpwd_check(iot)
1556469547: |-- ** checking backend http
1556469547: |-- url=http://127.0.0.1:8080/login
1556469547: |-- data=username=iot&password=xxxxxx&topic=&acc=-1&clientid=
[INFO] found iot on local database
1556469550: |-- getuser(iot) AUTHENTICATED=1 by http
1556469550: New client connected from 10.10.10.32 as Io (c1, k15, u’iot’).
1556469550: Client Io disconnected.
1556469674: New connection from 10.10.10.30 on port 1883.
1556469674: |-- mosquitto_auth_unpwd_check(iot)
1556469674: |-- ** checking backend http
1556469674: |-- url=http://127.0.0.1:8080/login
1556469674: |-- data=username=iot&password=xxxxxx&topic=&acc=-1&clientid=
[INFO] found iot on local database
1556469676: |-- getuser(iot) AUTHENTICATED=1 by http
1556469676: New client connected from 10.10.10.30 as kuchenbox (c1, k15, u’iot’).
1556469699: Client kuchenbox has exceeded timeout, disconnecting.
1556469699: Socket error on client kuchenbox, disconnecting.
1556469910: New connection from 10.10.10.30 on port 1883.
1556469910: |-- mosquitto_auth_unpwd_check(iot)
1556469910: |-- ** checking backend http
1556469910: |-- url=http://127.0.0.1:8080/login
1556469910: |-- data=username=iot&password=xxxxxx&topic=&acc=-1&clientid=
[INFO] found iot on local database
1556469912: |-- getuser(iot) AUTHENTICATED=1 by http
1556469912: New client connected from 10.10.10.30 as kuchenbox (c1, k15, u’iot’).
1556469913: Client kuchenbox disconnected.

push. Anyone any idea?

Hello,

Have you setup the Access Control List (ACL) yet?
In version 4.1 and above its required.
This should help. https://www.home-assistant.io/addons/mosquitto/#access-control-lists-acls.

However after the MQTT update >4.1 I see longer startup to ready times as well.

Hope it of help.

yes i added the ACL.

After troubleshooting with another mosquitto instance (and the help of mosquittos github forum), i figured out, that the delay is indeed introduced by homeassistant.
image