iotagent-ul does not reconnect to mqtt broker in case of failed connection

[chicco785]

when the mqtt broker stops or there are connectivity issues, the agent does not recover the connection correctly.

[Ashokkurukundi]

Eevn i am facing the same issue.... Plz help me

[tadeo-n]

Same problem. We are using iotagent 1.8.0 with docker.

[AlvaroVega]

Could you try with latest version please?

[tadeo-n]

With the latest version (1.13.0) the problem has been solved. Thank you

[fgalan]

@tadeo-n thanks for the positive feedback report! Maybe the issue should be closed. What do you think @chicco785 @Ashokkurukundi ?

[tadeo-n]

I update the status. Seems with 1.13.0 the problem is less frequent, but still occurs. When MQTT is restarted sometimes IoTAgent does not reconnect to MQTT Broker.

[fgalan]

When MQTT is restarted sometimes IoTAgent does not reconnect to MQTT Broker.

Under which circustances that occurs? Fully randomly? Or is the some pattern?

Note that is the problem cannot be reproduced it is extremely hard to debug and solve...

[tadeo-n]

For now we haven´t found any pattern.

The metrics reach MQTT but IoTAgent is not connecting to it, I don't see any errors on IoTAgent. MQTT is restarted but IoTAgent does not attempt reconnection.

IoTAgent restarts and the problem is solved.

We have updated the version of the MQTT Broker (we are using the eclipse-mosquitto image) to see if it fixes it (I don't think so) .

[AlvaroVega]

I was trying to reproduce your issue. Starting with iotagent ul and iotagent json and mosquitto running then I've stop mosquitto:

iot-iota-json               | time=2020-07-08T08:18:45.866Z | lvl=WARN | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=reconnecting... | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:45.867Z | lvl=WARN | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IOTAUL.MQTT.Binding | srv=n/a | subsrv=n/a | msg=reconnecting... | comp=IoTAgent
iot-mosquitto exited with code 137

And then I've start mosquitto again:

iot-iota-ul                 | time=2020-07-08T08:18:50.868Z | lvl=INFO | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IOTAUL.MQTT.Binding | srv=n/a | subsrv=n/a | msg=creating connection | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:50.868Z | lvl=INFO | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=creating connection | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:50.873Z | lvl=INFO | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=connected | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:50.873Z | lvl=INFO | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IOTAUL.MQTT.Binding | srv=n/a | subsrv=n/a | msg=connected | comp=IoTAgent
iot-mosquitto               | 2020-07-08T08:18:53: New connection from 172.17.0.17 on port 1883.
iot-mosquitto               | 2020-07-08T08:18:53: New connection from 172.17.0.16 on port 1883.
iot-mosquitto               | 2020-07-08T08:18:53: New client connected from 172.17.0.17 as mqttjs_6ceff15e (p2, c1, k0, u'iota').
iot-mosquitto               | 2020-07-08T08:18:53: New client connected from 172.17.0.16 as mqttjs_bbd1acb7 (p2, c1, k0, u'iota').
iot-iota-json               | time=2020-07-08T08:18:53.920Z | lvl=INFO | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=MQTT Client connected | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:53.920Z | lvl=INFO | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IOTAUL.MQTT.Binding | srv=n/a | subsrv=n/a | msg=MQTT Client connected | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:53.921Z | lvl=DEBUG | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IOTAUL.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Recreating global subscriptions | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:53.920Z | lvl=DEBUG | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Recreating subscriptions for all devices | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:53.921Z | lvl=DEBUG | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IOTAUL.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Generating topics | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:53.921Z | lvl=DEBUG | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Generating topics | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:53.921Z | lvl=DEBUG | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IoTAgentNGSI.MongoDBGroupRegister | srv=n/a | subsrv=n/a | msg=Subscribing to topics: ["$share/ul//+/+/attrs/+","$share/ul//ul/+/+/attrs/+","$share/ul//+/+/attrs","$share/ul//ul/+/+/attrs","$share/ul//+/+/configuration/commands","$share/ul//ul/+/+/configuration/commands","$share/ul//+/+/cmdexe","$share/ul//ul/+/+/cmdexe","$share/ul/+/+/attrs/+","$share/ul/ul/+/+/attrs/+","$share/ul/+/+/attrs","$share/ul/ul/+/+/attrs","$share/ul/+/+/configuration/commands","$share/ul/ul/+/+/configuration/commands","$share/ul/+/+/cmdexe","$share/ul/ul/+/+/cmdexe"] | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:53.922Z | lvl=DEBUG | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Subscribing to topics: ["$share/json//+/+/attrs/+","$share/json//json/+/+/attrs/+","$share/json//+/+/attrs","$share/json//json/+/+/attrs","$share/json//+/+/configuration/commands","$share/json//json/+/+/configuration/commands","$share/json//+/+/cmdexe","$share/json//json/+/+/cmdexe","$share/json//+/+/attrs/+","$share/json/json/+/+/attrs/+","$share/json//+/+/attrs","$share/json/json/+/+/attrs","$share/json//+/+/configuration/commands","$share/json/json/+/+/configuration/commands","$share/json//+/+/cmdexe","$share/json/json/+/+/cmdexe"] | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:53.927Z | lvl=DEBUG | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IoTAgentNGSI.MongoDBGroupRegister | srv=n/a | subsrv=n/a | msg=Successfully subscribed to the following topics:
iot-iota-ul                 | ["$share/ul//+/+/attrs/+","$share/ul//ul/+/+/attrs/+","$share/ul//+/+/attrs","$share/ul//ul/+/+/attrs","$share/ul//+/+/configuration/commands","$share/ul//ul/+/+/configuration/commands","$share/ul//+/+/cmdexe","$share/ul//ul/+/+/cmdexe","$share/ul/+/+/attrs/+","$share/ul/ul/+/+/attrs/+","$share/ul/+/+/attrs","$share/ul/ul/+/+/attrs","$share/ul/+/+/configuration/commands","$share/ul/ul/+/+/configuration/commands","$share/ul/+/+/cmdexe","$share/ul/ul/+/+/cmdexe"]
iot-iota-ul                 |  | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:53.928Z | lvl=DEBUG | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Successfully subscribed to the following topics:
iot-iota-json               | ["$share/json//+/+/attrs/+","$share/json//json/+/+/attrs/+","$share/json//+/+/attrs","$share/json//json/+/+/attrs","$share/json//+/+/configuration/commands","$share/json//json/+/+/configuration/commands","$share/json//+/+/cmdexe","$share/json//json/+/+/cmdexe","$share/json//+/+/attrs/+","$share/json/json/+/+/attrs/+","$share/json//+/+/attrs","$share/json/json/+/+/attrs","$share/json//+/+/configuration/commands","$share/json/json/+/+/configuration/commands","$share/json//+/+/cmdexe","$share/json/json/+/+/cmdexe"]
iot-iota-json               |  | comp=IoTAgent
iot-mosquitto               | 2020-07-08T08:18:54: New connection from 172.17.0.16 on port 1883.
iot-mosquitto               | 2020-07-08T08:18:54: New connection from 172.17.0.17 on port 1883.
iot-mosquitto               | 2020-07-08T08:18:54: New client connected from 172.17.0.16 as mqttjs_52622ac2 (p2, c1, k0, u'iota').
iot-mosquitto               | 2020-07-08T08:18:54: New client connected from 172.17.0.17 as mqttjs_6676d5aa (p2, c1, k0, u'iota').
iot-iota-ul                 | time=2020-07-08T08:18:54.082Z | lvl=INFO | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IOTAUL.MQTT.Binding | srv=n/a | subsrv=n/a | msg=MQTT Client connected | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:54.082Z | lvl=DEBUG | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IOTAUL.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Recreating global subscriptions | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:54.083Z | lvl=DEBUG | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IOTAUL.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Generating topics | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:54.083Z | lvl=DEBUG | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IoTAgentNGSI.MongoDBGroupRegister | srv=n/a | subsrv=n/a | msg=Subscribing to topics: ["$share/ul//+/+/attrs/+","$share/ul//ul/+/+/attrs/+","$share/ul//+/+/attrs","$share/ul//ul/+/+/attrs","$share/ul//+/+/configuration/commands","$share/ul//ul/+/+/configuration/commands","$share/ul//+/+/cmdexe","$share/ul//ul/+/+/cmdexe","$share/ul/+/+/attrs/+","$share/ul/ul/+/+/attrs/+","$share/ul/+/+/attrs","$share/ul/ul/+/+/attrs","$share/ul/+/+/configuration/commands","$share/ul/ul/+/+/configuration/commands","$share/ul/+/+/cmdexe","$share/ul/ul/+/+/cmdexe"] | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:54.082Z | lvl=INFO | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=MQTT Client connected | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:54.082Z | lvl=DEBUG | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Recreating subscriptions for all devices | comp=IoTAgent
iot-iota-ul                 | time=2020-07-08T08:18:54.084Z | lvl=DEBUG | corr=501d9147-513c-44e2-aaea-46794099586d | trans=501d9147-513c-44e2-aaea-46794099586d | op=IoTAgentNGSI.MongoDBGroupRegister | srv=n/a | subsrv=n/a | msg=Successfully subscribed to the following topics:
iot-iota-ul                 | ["$share/ul//+/+/attrs/+","$share/ul//ul/+/+/attrs/+","$share/ul//+/+/attrs","$share/ul//ul/+/+/attrs","$share/ul//+/+/configuration/commands","$share/ul//ul/+/+/configuration/commands","$share/ul//+/+/cmdexe","$share/ul//ul/+/+/cmdexe","$share/ul/+/+/attrs/+","$share/ul/ul/+/+/attrs/+","$share/ul/+/+/attrs","$share/ul/ul/+/+/attrs","$share/ul/+/+/configuration/commands","$share/ul/ul/+/+/configuration/commands","$share/ul/+/+/cmdexe","$share/ul/ul/+/+/cmdexe"]
iot-iota-ul                 |  | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:54.083Z | lvl=DEBUG | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Generating topics | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:54.083Z | lvl=DEBUG | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Subscribing to topics: ["$share/json//+/+/attrs/+","$share/json//json/+/+/attrs/+","$share/json//+/+/attrs","$share/json//json/+/+/attrs","$share/json//+/+/configuration/commands","$share/json//json/+/+/configuration/commands","$share/json//+/+/cmdexe","$share/json//json/+/+/cmdexe","$share/json//+/+/attrs/+","$share/json/json/+/+/attrs/+","$share/json//+/+/attrs","$share/json/json/+/+/attrs","$share/json//+/+/configuration/commands","$share/json/json/+/+/configuration/commands","$share/json//+/+/cmdexe","$share/json/json/+/+/cmdexe"] | comp=IoTAgent
iot-iota-json               | time=2020-07-08T08:18:54.084Z | lvl=DEBUG | corr=829bb753-7ca2-419a-8b39-504c472efb15 | trans=829bb753-7ca2-419a-8b39-504c472efb15 | op=IOTAJSON.MQTT.Binding | srv=n/a | subsrv=n/a | msg=Successfully subscribed to the following topics:
iot-iota-json               | ["$share/json//+/+/attrs/+","$share/json//json/+/+/attrs/+","$share/json//+/+/attrs","$share/json//json/+/+/attrs","$share/json//+/+/configuration/commands","$share/json//json/+/+/configuration/commands","$share/json//+/+/cmdexe","$share/json//json/+/+/cmdexe","$share/json//+/+/attrs/+","$share/json/json/+/+/attrs/+","$share/json//+/+/attrs","$share/json/json/+/+/attrs","$share/json//+/+/configuration/commands","$share/json/json/+/+/configuration/commands","$share/json//+/+/cmdexe","$share/json/json/+/+/cmdexe"]
iot-iota-json               |  | comp=IoTAgent

[AlvaroVega]

Are you using any of these options? https://github.com/telefonicaid/iotagent-json/blob/master/docs/installationguide.md#mqtt-configuration https://github.com/telefonicaid/iotagent-ul/blob/master/docs/installationguide.md#mqtt-binding-configuration

retries: Number of MQTT connection error retries (default is 5). retryTime: Time between MQTT connection retries (default is 5 seconds).

[tadeo-n]

Thanks Alvaro. Now we are using this parameters:

      - "IOTA_MQTT_RETRIES=200"
      - "IOTA_MQTT_RETRY_TIME=10"

Seems it's working on test environment. Let us try for a while in production. I answer when I have verified.

[onrao]

Hi tadeo-n

Can we know is it stabilized and fixed? any observations such that we can take it up for our deployment as well.