LOG INFO: Try to restore connection to IP & Starting MQTT broker connection every 60 seconds in LOG

Setup, Configuration and Use Installation
1

Hello,

I´m running openhab on Raspberry PI 4 with openhabian 1.5 - fresh installation, 1 month old.
I configured several things and also an MQTT broker (using openhabian - so Mosquito directly on the Raspberry is used).

Here´s my mqtt.things configuration:

Bridge mqtt:broker:home “Mosquitto MQTT Broker @home” [
host=“localhost”,
secure=false,
port=1883,
qos=0,
retain=false,
clientid=“openhab”,
//certificate=“”,
//certificatepin=false,
//publickey=“”,
//publickeypin=false,
keep_alive_time=30000,
reconnect_time=60000,
//lastwill_message=“”,
//lastwill_qos=1,
//lastwill_topic=“”,
username=“openhabian”,
password=“password”
]

//Steckdose Waschmaschine RECHTS
Thing mqtt:topic:steckdose_waschmaschine “Steckdose Waschmaschine” (mqtt:broker:home) {

Type switch:channel1 “Steckdose Waschmaschine” [ stateTopic=“stat/steckdose_waschmaschine/POWER1”, commandTopic=“cmnd/steckdose_waschmaschine/POWER1”, on=“ON”, off=“OFF” ]
Type number:power “Steckdose Waschmaschine aktueller Verbrauch” [ stateTopic=“tele/steckdose_waschmaschine/SENSOR”, transformationPattern=“JSONPATH:$.ENERGY.Power”]

Everything is running fine, I can retrieve values and so on but in the LOG File I have the following INFO every MINUTE:

2020-07-05 17:15:49.579 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to ‘192.168.1.199’. Next attempt in 60000ms

2020-07-05 17:15:49.587 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to ‘192.168.1.199’ with clientid c0830b37-35a0-4ee4-849c-741e2944e7c7

2020-07-05 17:16:49.595 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to ‘192.168.1.199’. Next attempt in 60000ms

2020-07-05 17:16:49.603 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to ‘192.168.1.199’ with clientid c0830b37-35a0-4ee4-849c-741e2944e7c7

2020-07-05 17:17:49.606 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to ‘192.168.1.199’. Next attempt in 60000ms

2020-07-05 17:17:49.613 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to ‘192.168.1.199’ with clientid c0830b37-35a0-4ee4-849c-741e2944e7c7

2020-07-05 17:18:49.621 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to ‘192.168.1.199’. Next attempt in 60000ms

192.168.1.199 is the IP address of my openhabian /raspberry.
Can anybody help me out how get rid of these information logs? Why is it loosing the connection and restoring it all the time?

My mqtt.items:

Switch Steckdose_Waschmaschine “Steckdose Waschmaschine” { channel=“mqtt:topic:steckdose_waschmaschine:channel1”}
Number Steckdose_Waschmaschine_Power “Aktueller Verbrauch [%.2f W]” { channel=“mqtt:topic:steckdose_waschmaschine:power”}
Number Steckdose_Waschmaschine_Status “Waschmaschinen Status”

Many thanks in advance!

Br,
Mario

2

Have you tried commenting out these two lines in your config?

You can also try just a basic config like:

Bridge mqtt:broker:pibroker "pibroker" [ host="10.0.1.15", port=1883, secure=false, username="xxxxxx", password="xxxxxxxx" ]

If that works without errors then add the extras you want one at a time to see what causes the error to return.

3

Do you have any invalid addons defined? That will cause ALL addons to reload every minute, trying to load the invalid one.

This could be an issue especially if you restored a configuration from an older OH version.

1 Like
4

Tried your suggestion but the Log Info stays the same.

Anyhow you input is much appreciated!

5

No. It was a complete new installation of openhab. All other addons/bindings are running smoothly.

6

Remove the @home part in your bridge config.

7

Have a look in your PaperUI for multiple broker Things

8

Removed the @home part. Logs are still the same…

9

In the Paper UI there´s only one Thing regarding MQTT:

MQTT Broker
mqtt:broker:home
Status: Online

Any other ideas? Thank you.

10

Have a look at its properties. I was curious that the log you are reporting does not have the same clientid as your things file.

11

Hm…i´m configuring everything with the files in Visual Studio. Anyhow I checked also settings in Paper UI but couldn´t find anything about it.

Still the same log entries every few minutes:

[.reconnect.PeriodicReconnectStrategy] - Try to restore connection to ‘192.168.1.199’. Next attempt in 60000ms

[.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to ‘192.168.1.199’ with clientid 89077518-cc96-4dfb-9bc7-c7ebe12e820c

12

If you couldn’t find anything, you’re looking in the wrong place. Clearly you have at least one broker Thing.

13

I had a similar issued except that I configured everything with paper ui.

Somehow there has been a mqtt broker as a thing and a second under services. I removed the entry in services and all works fine now.

I hope this will help someone.

2 Likes
14

I have this same issue, how were you able to delete the broker listed under services? I don’t have an option for that.

The binding seems to be working, but I have this reconnection loop every minute it seems.

My things are setup like below:

Thing mqtt:topic:espGarage “ESP Garage MQTT” (mqtt:broker:8e8e3f26) {
Channels:
Type number : temp “Temp” [ stateTopic=“esp/garage/temp” ]
Type number : humidity “Humidity” [ stateTopic=“esp/garage/humidity” ]
}

And my system broker is setup as mqtt:broker:8e8e3f26.

In my logs I see:

2020-12-24 22:18:08.722 [INFO ] [.reconnect.PeriodicReconnectStrategy] - Try to restore connection to ‘192.168.1.209’. Next attempt in 60000ms
2020-12-24 22:18:08.723 [INFO ] [.transport.mqtt.MqttBrokerConnection] - Starting MQTT broker connection to ‘192.168.1.209’ with clientid b995f190-1ad7-4f53-bbf2-510a058e06da

Just don’t get where the issue is. Any ideas? Thanks for the help!

15

I had the same issue but was able to solve it.
Sounds simple: I just had to restart openhab. I use the docker build which meant just doing a “docker restart openhab”.

Now I don’t have these kind of messages in my logs anymore. He is just complaining once that the broker config is faulty (which is true as I left everything blanc in the entry under “Other services”).
Maybe something in a cache which is purged when restarting the container but not in the installation directly on the OS?

I must say that this additional service entry confuses me as I don’t get for what it is needed as normally I would do like I did and define my own mqtt thing. I have no idea how I could use the other one. Maybe I’ll come to the bottom of this later…

16

I’ve rebooted countless times. It also seems that OH seems to stop running rules after a day or so if this happening, and I see “out of memory” errors in the log (like below). Not sure if this is related to the MQTT thing or not, but it seems all my other bindings are working properly, and I have no other strange items in my log

2020-12-27 15:42:17.653 [WARN ] [mmon.WrappedScheduledExecutorService] - Scheduled runnable ended with an exception:
java.lang.OutOfMemoryError: unable to create native thread: possibly out of memory or process/resource limits reached
at java.lang.Thread.start0(Native Method) ~[?:?]
at java.lang.Thread.start(Thread.java:803) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:937) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1343) ~[?:?]
at org.openhab.binding.network.internal.PresenceDetection.performPresenceDetection(PresenceDetection.java:362) ~[?:?]
at org.openhab.binding.network.internal.PresenceDetection.lambda$10(PresenceDetection.java:605) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515) ~[?:?]
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305) ~[?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:305) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
at java.lang.Thread.run(Thread.java:834) [?:?]

I’m really stuck here, short of not using MQTT. Anybody have any ideas? Thanks!!

17

Well, this OH3 installation was an upgrade from OH2. I actually tried to just upgrade to the latest 2 version, but had accidently switched the repository settings, and missed the fact that I was actually installing OH3. So I figured, what the heck try to get it working.

Anyway, this upgrade did not seem to work at all. Along with the MQTT errors listed above, the install would get memory errors, and would just stop working properly after a day.

So today, I backed up all my configs, uninstalled OH completely, upgrade my server packages, and installed OH3 fresh from scratch. Things seem to be working great now. Long story short – don’t try the upgrade!

18

I think i could fix it on my installation: I also did an upgrade to OH3, using a locally installed mosquitto service on my raspi.

i have configured mqtt.things via file and tried to check the MQTT broker service on my OH GUI.
OH3 => Settings => Other Services => MQTT system broker connection => activate “show advanced”.
after that i changed the value for “Keep-Alive”. Value was 60sec which exactly matches my logfiles.
I tried 20sec to check if this has an impact on my logfiles.

et voila: I got the following WARN log once:

2021-01-23 18:34:38.870 [WARN ] [.MqttBrokerConnectionServiceInstance] - Ignore existing broker connection configuration for: openhab-itself

after that change: no more “spam logfiles” from MQTT in my openhab.log and of course MQTT + OH3 still works fine :wink:

ps: after that I changed this value back to 60sec: once again the same WARN log, but no spam again.

image
image809×781 27 KB

5 Likes
19

bingo, that did it. must be some bug on the default connection it seems.

21

I have been seeing the same problem in my logs… this time I caused it!!!

Karaf log:

Try to restore connection to '192.168.5.25'. Next attempt in 60000ms 
Starting MQTT broker connection to '192.168.5.25' with clientid openHABServer

The Problem: I mistakenly used the same MQTT bridge configuration “ClientID” name on two instances of OH.

A few days ago I began creating a new OH installation running on a Pi4 to use in my truck (which will require MQTT) I just realized that I copied the bridge configuration verbatim.
Changing either OH instances bridge ClientID immediately resolved the problem

Bridge mqtt:broker:mosquitto "MQTT Broker: Mosquitto" 
[ 
        host="192.168.5.25", 
        port=1883,  
        clientID="openHABServer",     // these must be unique for each instance of OH
        keep_alive_time=10000,
        reconnect_time=20000,
        secure="false", 
        username="mqqtuser", 
        password="not4U2no"
]

My bad… Hope this helps someone else. :slight_smile:

1 Like