MQTT Connection lost by node-red

General
1

Hello everyone!
I've been reading a lot lately since i am diving deeper and deeper into the darkness of Home Automation.
I do have some experience on the mc-programming (mainly arduino and esps).

I am currently using node-red as a translator between homematic, mqtt, knx and influxdb.

My harware config is this:

HomeMatic CCU IP .180
KNX Multicast Gateway .25

Mosquitto in a Docker Container on a QNAP .10:1883
Node-Red in a Docker Container on QNAP with direct LAN .29:1880
InfluxDB in a Docker Container on QNAP with direct LAN .28
Grafana in a Docker Container on QNAP with direct LAN .30:3000

Several MQTT Clients on ESP8266 via WiFi

This setup used to work flawlessly. Since i had to do a restart and update of the QNAP Firmware, everything is still running flawlessly EXCEPT the MQTT Connection between Node-Red and mosquitto.

What is working?
I can access the Mosquitto Broker via MQTT Explorer from my Windows Machine.
In the Mosquitto log, i can see the ESP Devices connect and disconnect and publish messages (which i also see in the MQTT Explorer)
I can access Grafana, that displays the InfluxDB values.
Node-Red apparently still stores the Homematic Values into InfluxDB.

What is not working?
All MQTT Nodes within Node-Red do not connect, they remain yellow.

What did i try?
Re-create the Mosquitto Docker with or without mounted folders for log/lib
Re-create Node-Red, ofc with mounted folders so my flows do not get lost
Delete the MQTT config node and re-configuring it and all mqtt-nodes so there is just one Mosquitto client on node-red running.

Here is some random part of the mosquitto log:

1610043134: New client connected from 192.168.178.244 as ESP8266Client-5953 (c1, k15).                                                                       
1610043134: New connection from 192.168.178.241 on port 1883.                                                                                                
1610043134: New client connected from 192.168.178.241 as ESP8266Client-fde (c1, k15).                                                                        
1610043145: New connection from 192.168.178.29 on port 1883.                                                                                                 
1610043145: New client connected from 192.168.178.29 as mqtt_12f965e6.36d25a (c1, k15).                                                                      
1610043145: Socket error on client mqtt_12f965e6.36d25a, disconnecting.

The most similar problem thread here i could find is This one, althoug it seems that the issue over there were multiple mqtt instances within node-red.

Does anyone have any idea what could be the issue here?

2

Are you running the latest version of node red? I think there was an mqtt problem in a recent version.

3

Thanks for your answer. You had me hoping this was it for a second, as i had v1.2.5 installed. I just updated to v1.2.7 - unfortunately it is still the same behavior.

4

Can you show the full node red startup log please. Perhaps there is something helpful there.

5

Hi, here it is:

> node-red-docker@1.2.7 start /usr/src/node-red                                                                                                                                                                                    
> node $NODE_OPTIONS node_modules/node-red/red.js $FLOWS "--userDir" "/data"                                                                                                                                                       
                                                                                                                                                                                                                                   
8 Jan 08:11:02 - [info]                                                                                                                                                                                                            
                                                                                                                                                                                                                                   
Welcome to Node-RED                                                                                                                                                                                                                
===================                                                                                                                                                                                                                
                                                                                                                                                                                                                                   
8 Jan 08:11:02 - [info] Node-RED version: v1.2.7                                                                                                                                                                                   
8 Jan 08:11:02 - [info] Node.js  version: v10.23.1                                                                                                                                                                                 
8 Jan 08:11:02 - [info] Linux 4.14.24-qnap x64 LE                                                                                                                                                                                  
8 Jan 08:11:03 - [info] Loading palette nodes                                                                                                                                                                                      
8 Jan 08:11:05 - [info] node-red-contrib-ccu version: 3.2.0                                                                                                                                                                        
8 Jan 08:11:05 - [info] Settings file  : /data/settings.js                                                                                                                                                                         
8 Jan 08:11:05 - [info] Context store  : 'default' [module=memory]                                                                                                                                                                 
8 Jan 08:11:05 - [info] User directory : /data                                                                                                                                                                                     
8 Jan 08:11:05 - [warn] Projects disabled : editorTheme.projects.enabled=false                                                                                                                                                     
8 Jan 08:11:05 - [info] Flows file     : /data/flows.json                                                                                                                                                                          
8 Jan 08:11:06 - [warn]                                                                                                                                                                                                            
                                                                                                                                                                                                                                   
---------------------------------------------------------------------                                                                                                                                                              
Your flow credentials file is encrypted using a system-generated key.                                                                                                                                                              
                                                                                                                                                                                                                                   
If the system-generated key is lost for any reason, your credentials                                                                                                                                                               
file will not be recoverable, you will have to delete it and re-enter                                                                                                                                                              
your credentials.                                                                                                                                                                                                                  
                                                                                                                                                                                                                                   
You should set your own key using the 'credentialSecret' option in                                                                                                                                                                 
your settings file. Node-RED will then re-encrypt your credentials                                                                                                                                                                 
file using your chosen key the next time you deploy a change.                                                                                                                                                                      
---------------------------------------------------------------------                                                                                                                                                              
                                                                                                                                                                                                                                   
8 Jan 08:11:06 - [info] Starting flows                                                                                                                                                                                             
8 Jan 08:11:06 - [info] [ccu-connection:192.168.178.180] paramsets loaded from /data/paramsets.json                                                                                                                                
8 Jan 08:11:06 - [info] [ccu-connection:192.168.178.180] metadata loaded from /data/ccu_192.168.178.180.json                                                                                                                       
8 Jan 08:11:06 - [info] [ccu-connection:192.168.178.180] regadata loaded from /data/ccu_rega_192.168.178.180.json                                                                                                                  
8 Jan 08:11:06 - [info] KNXUltimate-config: no ESF found                                                                                                                                                                           
8 Jan 08:11:06 - [info] Started flows                                                                                                                                                                                              
8 Jan 08:11:06 - [info] Server now running at http://127.0.0.1:1880/                                                                                                                                                               
8 Jan 08:11:07 - [info] [mqtt-broker:mosquitto] Connection failed to broker: mqtt://192.168.178.10:1883                                                                                                                            
8 Jan 08:11:07 - [info] [ccu-connection:192.168.178.180] values saved to /data/ccu_values_192.168.178.180.json                                                                                                                     
8 Jan 08:11:07 - [info] [ccu-connection:192.168.178.180] Interfaces: ReGaHSS, BidCos-RF, HmIP-RF, VirtualDevices                                                                                                                   
8 Jan 08:11:07 - [info] [ccu-connection:192.168.178.180] Interface ReGaHSS connected                                                                                                                                               
8 Jan 08:11:07 - [info] [ccu-connection:192.168.178.180] init BidCos-RF http://192.168.178.29:2062 nr_Q83yra_BidCos-RF                                                                                                             
8 Jan 08:11:07 - [info] [ccu-connection:192.168.178.180] init HmIP-RF http://192.168.178.29:2062 nr_Q83yra_HmIP-RF                                                                                                                 
8 Jan 08:11:07 - [info] [ccu-connection:192.168.178.180] init VirtualDevices http://192.168.178.29:2062 nr_Q83yra_VirtualDevices                                                                                                   
8 Jan 08:11:07 - [info] [ccu-connection:192.168.178.180] xmlrpc server listening on http://192.168.178.29:2062                                                                                                                     
8 Jan 08:11:08 - [info] [ccu-connection:192.168.178.180] Interface BidCos-RF http port 2001 connected                                                                                                                              
8 Jan 08:11:08 - [info] [ccu-connection:192.168.178.180] regadata saved to /data/ccu_rega_192.168.178.180.json                                                                                                                     
8 Jan 08:11:08 - [info] [ccu-connection:192.168.178.180] Interface HmIP-RF http port 2010 connected                                                                                                                                
8 Jan 08:11:08 - [info] [ccu-connection:192.168.178.180] Interface VirtualDevices http port 9292 connected                                                                                                                         
8 Jan 08:11:09 - [info] [ccu-connection:192.168.178.180] metadata saved to /data/ccu_192.168.178.180.json                                                                                                                          
8 Jan 08:11:22 - [info] [mqtt-broker:mosquitto] Connection failed to broker: mqtt://192.168.178.10:1883                                                                                                                            
8 Jan 08:11:28 - [info] Stopping flows                                                                                                                                                                                           
8 Jan 08:11:28 - [info] [ccu-connection:192.168.178.180] regadata saved to /data/ccu_rega_192.168.178.180.json                                                                                                                     
8 Jan 08:11:28 - [info] [ccu-connection:192.168.178.180] values saved to /data/ccu_values_192.168.178.180.json                                                                                                                     
8 Jan 08:11:28 - [info] [ccu-connection:192.168.178.180] de-init BidCos-RF http://192.168.178.29:2062 done                                                                                                                         
8 Jan 08:11:28 - [info] [ccu-connection:192.168.178.180] de-init HmIP-RF http://192.168.178.29:2062 done                                                                                                                           
8 Jan 08:11:28 - [info] [ccu-connection:192.168.178.180] de-init VirtualDevices http://192.168.178.29:2062 done                                                                                                                    
8 Jan 08:11:28 - [info] [ccu-connection:192.168.178.180] xmlrpc server closed                                                                                                                                                      
8 Jan 08:11:28 - [info] [ccu-connection:192.168.178.180] rpc close done                                                                                                                                                            
8 Jan 08:11:28 - [info] Stopped flows
6

Is that IP address still the IP address of the broker?
Is the broker installed on the same machine as node-red?
have you verified the settings in the mqtt nodes has not changed?

7

It is odd, the fact that you can see it attempting to connect in the mosquitto log means that the IP address must be correct.
Are user/pwd required to connect to the broker?
Try starting node-red with trace logging enabled and see if that gives any more information, you can set the log level to trace in settings.js.
Also I don't know whether one can enable more detailed logging in mosquitto, probably it is possible, so have a look at that.

8

It certainly is. No there is no user/pwd required, which used to work just fine.

Trace logging shows a ****load of info about HM communication, but the MQTT part is still just

8 Jan 10:39:49 - [info] [mqtt-broker:mosquitto] Connection failed to broker: mqtt://192.168.178.10:1883

i'll see what i can do about the mosquitto logs.

9

Sorry, i don't want to be rude, but did you read my first post?

However..
Yes, the IP address of the broker is still correct, all other devices can access ist and it shows in the mosquitto log that node-red tries to connect but somehow fails.
No, it is not on the same machine as they are in two different docker containers.
Yes, i even tried to make a new node with the correct, verified settings i am using on other systems that are able to connect.

10

(Sorry, I did miss that part)

So this would seem to be a permissions/communications issue between the two dockers. I'll bow out since I don't use docker, but you might try pining the mqtt docker from the node-red docker to make sure it works. Good Luck.

11

The fact that the mosquitto log shows that an initial connection is made means that it can't be as simple as not able to see the IP, I think.

12

you mention that you recreated the Docker image

There were some breaking changes in mosquitto broker as described in this link
Version 2.0.0 released
by default now mosquitto is not open to connections except to localhost / 127.0.0.1

possibly it could be a similar issue as described in this very recent post

13

But other devices CAN connect to Mosquitto, when you read his log in the first post!?

14

Yes, it is odd, we are missing something.

15

Alright, i tried several different MQTT Docker Images. The first one i used was the "official" QNAP MQTT Docker. Then some others from different forks.

The most detailed log i got from it was this:

1610192661: New client connected from 192.168.178.29 as mqtt_d476e4a9.fbd638 (p2, c1, k15).                                                             
1610192661: No will message specified.                                                                                                                  
1610192661: Sending CONNACK to mqtt_d476e4a9.fbd638 (0, 0)                                                                                              
1610192661: Socket error on client mqtt_d476e4a9.fbd638, disconnecting.
16

Thanks. As others already said, other external devices CAN connect. And currently i have v1.6.12 installed. I was not yet able to figure out how to configure the v2.x for external access from within docker.

17

With the "no will message specified" log entry i was able to find this issue which seems to come from switching between clean and persistent connections from the same host.

Since right now i do not have any host folders mounted, mosquitto is starting clean with default settings everytime, so there can not be any leftover entries from former sessions.

I also tried setting node-red to persistent with a fixed id, still not better:

1610194788: Received PUBLISH from ESP8266Client-10ef (d0, q0, r0, m0, 'esp/temp/schlafzimmer', ... (6 bytes))                                              
1610194788: Received PUBLISH from ESP8266Client-10ef (d0, q0, r0, m0, 'esp/hum/schlafzimmer', ... (6 bytes))                                               
1610194788: Received PINGREQ from ESP8266Client-10ef                                                                                                       
1610194788: Sending PINGRESP to ESP8266Client-10ef                                                                                                         
1610194793: Received PUBLISH from ESP8266Client-e770 (d0, q0, r0, m0, 'esp/temp/wintergarten2', ... (6 bytes))                                             
1610194793: Received PUBLISH from ESP8266Client-e770 (d0, q0, r0, m0, 'esp/hum/wintergarten', ... (6 bytes))                                               
1610194793: Received PINGREQ from ESP8266Client-e770                                                                                                       
1610194793: Sending PINGRESP to ESP8266Client-e770                                                                                                         
1610194798: New connection from 192.168.178.29 on port 1883.                                                                                               
1610194798: New client connected from 192.168.178.29 as nodered-mqtt-client (p2, c0, k15).                                                                 
1610194798: No will message specified.                                                                                                                     
1610194798: Sending CONNACK to nodered-mqtt-client (1, 0)                                                                                                  
1610194798: Socket error on client nodered-mqtt-client, disconnecting.
18

Try setting a Will message in the node red config. Though I don't expect it to make any difference other than clearing that message.

Edit: Also, have you tried setting the log_type in mosquitto.conf to debug?
It might be best to switch off the other devices when you do that as you will likely get a lot of output.

19

I still have no idea what the issue here is / was. But: Now it's working!

What i did was to migrate mosquitto to v2.0.4 with an edited mosquitto.conf with allow_anonymous = true and default listener on 1883 instead of the "old" v1.6.12.

The second change was to not put it in a NAT Layer Docker via the QNAP Host but with a LAN Bridge with it's own IP and a fixed MAC Address.

MQTT Explorer and Node-Red can successfully connect. Eureka!
I will now start to change the ESP-devices to the new MQTT Host to see if one of them caused the problem in the first place, although i believe it was caused by some issues with "old" mosquitto on broker and "new" mosquitto on nodered.

3 Likes
20

This topic was automatically closed 60 days after the last reply. New replies are no longer allowed.