search

Supergiovane / node-red-contrib-knx-ultimate

Control your KNX intallation via Node-Red! A bunch of KNX nodes, with integrated Philips HUE control and ETS group address importer.
https://youtu.be/egRbR_KwP9I
MIT License
154 stars 34 forks source link

KNXUltimate error #392

Closed gtnscebba closed 1 week ago

gtnscebba commented 3 weeks ago

Ciao Massimo, I use your fantastic palette KNXUltimate (3.2.16) on a Raspberry PI 4B (Linux PI4 6.6.51+rpt-rpi-v8 #1 SMP PREEMPT Debian 1:6.6.51-1+rpt3 (2024-10-08) aarch64 GNU/Linux).

On the journal I see the following messages:

Nov 09 12:16:03 PI4 Node-RED[19987]: 09/11/2024, 12:16:03 [KNXEngine] [ERROR] Received KNX packet: DISCONNECT_REQUEST, ChannelID:91 Host:192.168.1.200:3671
Nov 09 12:16:11 PI4 Node-RED[19987]: 09/11/2024, 12:16:11 [KNXEngine] [ERROR] KNXClient: into async closeSocket(): Error: Not running
Nov 09 12:16:11 PI4 Node-RED[19987]:     at healthCheck (node:dgram:924:11)
Nov 09 12:16:11 PI4 Node-RED[19987]:     at Socket.close (node:dgram:749:3)
Nov 09 12:16:11 PI4 Node-RED[19987]:     at /home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1130:41
Nov 09 12:16:11 PI4 Node-RED[19987]:     at new Promise (<anonymous>)
Nov 09 12:16:11 PI4 Node-RED[19987]:     at KNXClient.closeSocket (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1116:10)
Nov 09 12:16:11 PI4 Node-RED[19987]:     at KNXClient.Disconnect (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1165:15)
Nov 09 12:16:11 PI4 Node-RED[19987]:     at knxUltimateConfigNode.node.initKNXConnection (/home/pi/.node-red/node_modules/node-red-contrib-knx-ultimate/nodes/knxUltimate-config.js:618:38)
Nov 09 12:16:14 PI4 Node-RED[19987]: 09/11/2024, 12:16:14 [knxUltimate-config <Casa>] [ERROR] unable to read peristent file /home/pi/.node-red/knxultimatestorage/knxpersistvalues/knxpersist9c9a0a6192701747.json ENOENT: no such file or directory, open '/home/pi/.node-red/knxultimatestorage/knxpersistvalues/knxpersist9c9a0a6192701747.json'

Effectively, the json file is not present on that directory.

Knx-Ultimate Version

Are you running node-red behind homematic, docker or anything similar? Nodered (4.0.5) is stand-alone.

This error can be corrected?

Ciao

gtnscebba commented 3 weeks ago

After a restart of NodeRed the problem disappeared.

Supergiovane commented 3 weeks ago

Hi! Your knx ip gateway is forcing a disconnection. Please verify you’re not running out of free tunnels, by restarting the knx ip interface. It could happen again if you’re using too many tunnels.

gtnscebba commented 3 weeks ago

Before the restart of NodeRed, despite the error, the nodes worked. The only anomaly was a slow response. For example, if on the dashboard (2) you clicked on the switch to turn on/off a light, it was turned on/off but with a delay of about half a second. After the restart of NodeRed, there are no more messages in the journal and the on/off action occurs immediately. It was not necessary to restart the IP Gateway of the KNX bus. I do not use too many tunnels, in reality only the NodeRed and ETS ones when I have to sporadically reconfigure something. Thanks!

gtnscebba commented 2 weeks ago

Good Morning Massimo, I reopen this issue because yesterday, after a couple of hours, KNXUltimate didn't work correctly. This morning I have done: 1) a reset of the KNX IP Gateway 2) restart NodeRed

Now, on the journal there are many messages like this:

Nov 10 08:21:03 PI4 systemd[1]: Started user@1000.service - User Manager for UID 1000.
Nov 10 08:21:03 PI4 systemd[1]: Started session-11.scope - Session 11 of User pi.
Nov 10 08:25:31 PI4 Node-RED[436]: 10 Nov 08:25:31 - [info] [ui-base:My Dashboard] Disconnected ezNkaeigsDYEc4RVAAAK due to ping timeout
Nov 10 08:30:05 PI4 Node-RED[436]: 10/11/2024, 08:30:05 [KNXEngine] [ERROR] Received KNX packet: DISCONNECT_REQUEST, ChannelID:18 Host:192.168.1.200:3671
Nov 10 08:30:06 PI4 Node-RED[436]: 10/11/2024, 08:30:06 [KNXEngine] [ERROR] Sending KNX packet: Send UDP Catch error: Not running object seqCounter:78
Nov 10 08:30:06 PI4 Node-RED[436]: 10/11/2024, 08:30:06 [KNXEngine] [ERROR] Error: Not running
Nov 10 08:30:06 PI4 Node-RED[436]:     at healthCheck (node:dgram:924:11)
Nov 10 08:30:06 PI4 Node-RED[436]:     at Socket.send (node:dgram:651:3)
Nov 10 08:30:06 PI4 Node-RED[436]:     at KNXClient.processKnxPacketQueueItem (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:501:40)
Nov 10 08:30:06 PI4 Node-RED[436]:     at KNXClient.handleKNXQueue (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:561:16)
Nov 10 08:30:06 PI4 Node-RED[436]: 10/11/2024, 08:30:06 [knxUltimate-config <Casa>] [ERROR] received KNXClientEvents.error: Not running
Nov 10 08:30:06 PI4 Node-RED[436]: 10/11/2024, 08:30:06 [knxUltimate-config <Casa>] [ERROR] Disconnected by: Not running
Nov 10 08:30:11 PI4 Node-RED[436]: 10/11/2024, 08:30:11 [KNXEngine] [ERROR] KNXClient: into async closeSocket(): Error: Not running
Nov 10 08:30:11 PI4 Node-RED[436]:     at healthCheck (node:dgram:924:11)
Nov 10 08:30:11 PI4 Node-RED[436]:     at Socket.close (node:dgram:749:3)
Nov 10 08:30:11 PI4 Node-RED[436]:     at /home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1130:41
Nov 10 08:30:11 PI4 Node-RED[436]:     at new Promise (<anonymous>)
Nov 10 08:30:11 PI4 Node-RED[436]:     at KNXClient.closeSocket (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1116:10)
Nov 10 08:30:11 PI4 Node-RED[436]:     at KNXClient.Disconnect (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1165:15)
Nov 10 08:30:11 PI4 Node-RED[436]:     at knxUltimateConfigNode.node.initKNXConnection (/home/pi/.node-red/node_modules/node-red-contrib-knx-ultimate/nodes/knxUltimate-config.js:618:38)
Nov 10 08:33:06 PI4 Node-RED[436]: 10/11/2024, 08:33:06 [KNXEngine] [ERROR] Received KNX packet: DISCONNECT_REQUEST, ChannelID:19 Host:192.168.1.200:3671
Nov 10 08:33:07 PI4 Node-RED[436]: 10/11/2024, 08:33:07 [KNXEngine] [ERROR] Sending KNX packet: Send UDP Catch error: Not running object seqCounter:37
Nov 10 08:33:07 PI4 Node-RED[436]: 10/11/2024, 08:33:07 [KNXEngine] [ERROR] Error: Not running
Nov 10 08:33:07 PI4 Node-RED[436]:     at healthCheck (node:dgram:924:11)
Nov 10 08:33:07 PI4 Node-RED[436]:     at Socket.send (node:dgram:651:3)
Nov 10 08:33:07 PI4 Node-RED[436]:     at KNXClient.processKnxPacketQueueItem (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:501:40)
Nov 10 08:33:07 PI4 Node-RED[436]:     at KNXClient.handleKNXQueue (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:561:16)
Nov 10 08:33:07 PI4 Node-RED[436]: 10/11/2024, 08:33:07 [knxUltimate-config <Casa>] [ERROR] received KNXClientEvents.error: Not running
Nov 10 08:33:07 PI4 Node-RED[436]: 10/11/2024, 08:33:07 [knxUltimate-config <Casa>] [ERROR] Disconnected by: Not running
Nov 10 08:33:14 PI4 Node-RED[436]: 10/11/2024, 08:33:14 [KNXEngine] [ERROR] KNXClient: into async closeSocket(): Error: Not running
Nov 10 08:33:14 PI4 Node-RED[436]:     at healthCheck (node:dgram:924:11)
Nov 10 08:33:14 PI4 Node-RED[436]:     at Socket.close (node:dgram:749:3)
Nov 10 08:33:14 PI4 Node-RED[436]:     at /home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1130:41
Nov 10 08:33:14 PI4 Node-RED[436]:     at new Promise (<anonymous>)
Nov 10 08:33:14 PI4 Node-RED[436]:     at KNXClient.closeSocket (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1116:10)
Nov 10 08:33:14 PI4 Node-RED[436]:     at KNXClient.Disconnect (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1165:15)
Nov 10 08:33:14 PI4 Node-RED[436]:     at knxUltimateConfigNode.node.initKNXConnection (/home/pi/.node-red/node_modules/node-red-contrib-knx-ultimate/nodes/knxUltimate-config.js:618:38)
Nov 10 08:34:05 PI4 Node-RED[436]: 10/11/2024, 08:34:05 [KNXEngine] [ERROR] Received KNX packet: DISCONNECT_REQUEST, ChannelID:20 Host:192.168.1.200:3671
Nov 10 08:34:06 PI4 Node-RED[436]: 10/11/2024, 08:34:06 [KNXEngine] [ERROR] Sending KNX packet: Send UDP Catch error: Not running object seqCounter:11
Nov 10 08:34:06 PI4 Node-RED[436]: 10/11/2024, 08:34:06 [KNXEngine] [ERROR] Error: Not running
Nov 10 08:34:06 PI4 Node-RED[436]:     at healthCheck (node:dgram:924:11)
Nov 10 08:34:06 PI4 Node-RED[436]:     at Socket.send (node:dgram:651:3)
Nov 10 08:34:06 PI4 Node-RED[436]:     at KNXClient.processKnxPacketQueueItem (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:501:40)
Nov 10 08:34:06 PI4 Node-RED[436]:     at KNXClient.handleKNXQueue (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:561:16)
Nov 10 08:34:06 PI4 Node-RED[436]: 10/11/2024, 08:34:06 [knxUltimate-config <Casa>] [ERROR] received KNXClientEvents.error: Not running
Nov 10 08:34:06 PI4 Node-RED[436]: 10/11/2024, 08:34:06 [knxUltimate-config <Casa>] [ERROR] Disconnected by: Not running
Nov 10 08:34:11 PI4 Node-RED[436]: 10/11/2024, 08:34:11 [KNXEngine] [ERROR] KNXClient: into async closeSocket(): Error: Not running
Nov 10 08:34:11 PI4 Node-RED[436]:     at healthCheck (node:dgram:924:11)
Nov 10 08:34:11 PI4 Node-RED[436]:     at Socket.close (node:dgram:749:3)
Nov 10 08:34:11 PI4 Node-RED[436]:     at /home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1130:41
Nov 10 08:34:11 PI4 Node-RED[436]:     at new Promise (<anonymous>)
Nov 10 08:34:11 PI4 Node-RED[436]:     at KNXClient.closeSocket (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1116:10)
Nov 10 08:34:11 PI4 Node-RED[436]:     at KNXClient.Disconnect (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1165:15)
Nov 10 08:34:11 PI4 Node-RED[436]:     at knxUltimateConfigNode.node.initKNXConnection (/home/pi/.node-red/node_modules/node-red-contrib-knx-ultimate/nodes/knxUltimate-config.js:618:38)

What I can do?

Ciao!

PS: the debug level is "Error"

Supergiovane commented 2 weeks ago

Hi You gotta timeouts yet. you should inspect the memory/cpu consumption, because i think you’ve something wrong. Maybe something you updated recently, or something you installed. You should consider runnig 2 rpi. One for KNX and another for the rest, so you won’t be running in problems if some node isn’t working/developed properly.

gtnscebba commented 2 weeks ago

This problem started when I installed KNXUltimate version 3.2.16. Unfortunately it is not working well. In the status message under the nodes (all of them) there are continuous messages of the type "Connected. On duty. ... Retry connection". As said I reset the Gateway IP and the only client that is using it is your palette. The messages in the journal are continuous.

The configuration node of your palette is:

image

Supergiovane commented 2 weeks ago

Hi Do you have both WiFi and Ethernet enabled? If so, select an interface to bind to. Other than that, please let me see the “advanced” tab.

gtnscebba commented 2 weeks ago

On the Raspberry, the WiFi is disabled.

This is the Advanced Tab: image

gtnscebba commented 2 weeks ago

The status of storage is:

pi@PI4:~ $ df -h
Filesystem      Size  Used Avail Use% Mounted on
udev            1.6G     0  1.6G   0% /dev
tmpfs           380M  1.2M  379M   1% /run
/dev/mmcblk0p2   59G  4.2G   51G   8% /
tmpfs           1.9G     0  1.9G   0% /dev/shm
tmpfs           5.0M   20K  5.0M   1% /run/lock
/dev/mmcblk0p1  510M   97M  414M  19% /boot/firmware
Dropbox:        2.5G   12M  2.5G   1% /home/pi/Dropbox
GDrive:         102G   72G   31G  71% /home/pi/GDrive
tmpfs           380M     0  380M   0% /run/user/1000
pi@PI4:~ $

Regarding the memory:

top - 09:21:34 up  3:10,  1 user,  load average: 0.34, 0.37, 0.36
Tasks: 161 total,   1 running, 160 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.7 us,  1.7 sy,  0.0 ni, 97.3 id,  0.2 wa,  0.0 hi,  0.2 si,  0.0 st
MiB Mem :   3792.0 total,   3164.9 free,    357.5 used,    345.4 buff/cache
MiB Swap:    200.0 total,    200.0 free,      0.0 used.   3434.5 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
  436 pi        20   0  351928 221116  46848 S   2.6   5.7  39:25.20 node-red
   78 root       0 -20       0      0      0 I   1.0   0.0   0:03.63 kworker/u13:0-brcmf_wq/mmc1:0001:1
Supergiovane commented 2 weeks ago

Hi

PI4 Node-RED[436]: 10 Nov 08:25:31 - [info] [ui-base:My Dashboard] Disconnected ezNkaeigsDYEc4RVAAAK due to ping timeout

and followed by

10/11/2024, 08:34:05 [KNXEngine] [ERROR] Received KNX packet: DISCONNECT_REQUEST

suggests a sluggish machine. The disconnect_request is coming from your KNX IP Gateway, maybe due to throttling CPU. Try to enable "Suppress ACK requests". This should leverage the CPU and address some issues. Anyway, we must find the real culprit, otherwise the issue will soon arise again.

Supergiovane commented 2 weeks ago

PS: please issue also a "top" command from an ssh shell prompt. This shows all running processes/cpu usage.

gtnscebba commented 2 weeks ago

Done, but nothing is changed. Now, there are:

Nov 10 09:25:31 PI4 Node-RED[436]: 10/11/2024, 09:25:31 [knxUltimate-config <Casa>] [ERROR] unable to read peristent file /home/pi/.node-red/knxultimatestorage/knxpersistvalues/knxpersist9c9a0a6192701747.json ENOENT: no such file or directory, open '/home/pi/.node-red/knxultimatestorage/knxpersistvalues/knxpersist9c9a0a6192701747.json'

Supergiovane commented 2 weeks ago

Hi not an issue here. Once you enter the node config gateway, the persistent file is deleted. Have you restarted node-red after enabling "suppress ack..." checkbox?

gtnscebba commented 2 weeks ago

PS: please issue also a "top" command from an ssh shell prompt. This shows all running processes/cpu usage.

I have already done, however I do another top:

top - 09:28:01 up  3:17,  1 user,  load average: 0.25, 0.33, 0.35
Tasks: 164 total,   3 running, 161 sleeping,   0 stopped,   0 zombie
%Cpu(s): 32.2 us,  0.3 sy,  0.0 ni, 67.4 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   3792.0 total,   3160.8 free,    361.0 used,    346.0 buff/cache
MiB Swap:    200.0 total,    200.0 free,      0.0 used.   3431.0 avail Mem

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
  436 pi        20   0  359324 227468  46848 R 128.7   5.9  41:50.76 node-red
gtnscebba commented 2 weeks ago

Have you restarted node-red after enabling "suppress ack..." checkbox?

No, I restart Node-Red

gtnscebba commented 2 weeks ago

Restarted NodeRed: now it seems that your nodes are stable and on journal there are no messages (up to now). I'll monitor the situation.

Supergiovane commented 2 weeks ago

Can U tell me the make/model of your KNX IP Gateway?

gtnscebba commented 2 weeks ago

It is a Gewiss GW90767AP.

gtnscebba commented 2 weeks ago

Massimo, I confirm you that after restart, on the journal there are no messages from your palette. The node are stable, in other words they maintain their status, for example:

image

The situation represented above is for all other nodes (tens). Let me know something about KNX/IP Gateway, do I need to do something?

Thanks a lot

Supergiovane commented 2 weeks ago

What do you mean with “The node are stable, in other words they maintain their status” They don’t update according to the sent knx telegrams?

gtnscebba commented 2 weeks ago

What do you mean with “The node are stable, in other words they maintain their status”

As I said, the message under any KNXUltimate node, changes continuously, from "Connected. On duty" to "Retry connection".

gtnscebba commented 2 weeks ago

Unfortunately, after one hour there are new messages on journal and the status messages under the nodes change continuously:

Nov 10 11:54:20 PI4 Node-RED[1390]: 10/11/2024, 11:54:20 [KNXEngine] [ERROR] Received KNX packet: DISCONNECT_REQUEST, ChannelID:189 Host:192.168.1.200:3671
Nov 10 11:54:22 PI4 Node-RED[1390]: 10/11/2024, 11:54:22 [KNXEngine] [ERROR] Sending KNX packet: Send UDP Catch error: Not running object seqCounter:7
Nov 10 11:54:22 PI4 Node-RED[1390]: 10/11/2024, 11:54:22 [KNXEngine] [ERROR] Error: Not running
Nov 10 11:54:22 PI4 Node-RED[1390]:     at healthCheck (node:dgram:924:11)
Nov 10 11:54:22 PI4 Node-RED[1390]:     at Socket.send (node:dgram:651:3)
Nov 10 11:54:22 PI4 Node-RED[1390]:     at KNXClient.processKnxPacketQueueItem (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:501:40)
Nov 10 11:54:22 PI4 Node-RED[1390]:     at KNXClient.handleKNXQueue (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:561:16)
Nov 10 11:54:22 PI4 Node-RED[1390]: 10/11/2024, 11:54:22 [knxUltimate-config <Casa>] [ERROR] received KNXClientEvents.error: Not running
Nov 10 11:54:22 PI4 Node-RED[1390]: 10/11/2024, 11:54:22 [knxUltimate-config <Casa>] [ERROR] Disconnected by: Not running
Nov 10 11:54:28 PI4 Node-RED[1390]: 10/11/2024, 11:54:28 [KNXEngine] [ERROR] KNXClient: into async closeSocket(): Error: Not running
Nov 10 11:54:28 PI4 Node-RED[1390]:     at healthCheck (node:dgram:924:11)
Nov 10 11:54:28 PI4 Node-RED[1390]:     at Socket.close (node:dgram:749:3)
Nov 10 11:54:28 PI4 Node-RED[1390]:     at /home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1130:41
Nov 10 11:54:28 PI4 Node-RED[1390]:     at new Promise (<anonymous>)
Nov 10 11:54:28 PI4 Node-RED[1390]:     at KNXClient.closeSocket (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1116:10)
Nov 10 11:54:28 PI4 Node-RED[1390]:     at KNXClient.Disconnect (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1165:15)
Nov 10 11:54:28 PI4 Node-RED[1390]:     at knxUltimateConfigNode.node.initKNXConnection (/home/pi/.node-red/node_modules/node-red-contrib-knx-ultimate/nodes/knxUltimate-config.js:618:38)
Nov 10 11:54:31 PI4 Node-RED[1390]: 10/11/2024, 11:54:31 [knxUltimate-config <Casa>] [ERROR] unable to read peristent file /home/pi/.node-red/knxultimatestorage/knxpersistvalues/knxpersist9c9a0a6192701747.json ENOENT: no such file or directory, open '/home/pi/.node-red/knxultimatestorage/knxpersistvalues/knxpersist9c9a0a6192701747.json'

The folder is empty:

pi@PI4:~ $ ls -al /home/pi/.node-red/knxultimatestorage/knxpersistvalues/
total 8
drwxr-xr-x 2 pi pi 4096 Nov 10 08:51 .
drwxr-xr-x 4 pi pi 4096 Sep 17 07:42 ..
pi@PI4:~ $

NodeRed is not restarted.

gtnscebba commented 2 weeks ago

After a restart o NodeRed the file "knxpersist." has been re-created:

pi@PI4:~ $ ls -al /home/pi/.node-red/knxultimatestorage/knxpersistvalues/
total 12
drwxr-xr-x 2 pi pi 4096 Nov 10 12:01 .
drwxr-xr-x 4 pi pi 4096 Sep 17 07:42 ..
-rw-r--r-- 1 pi pi  124 Nov 10 12:01 knxpersist9c9a0a6192701747.json
pi@PI4:~ $

In the journal there are not error messages and the status messages of the KNXUltimate nodes do not change, they remain fixed:

image

Supergiovane commented 2 weeks ago

You could try downgrading knx ultimate, but the main issue is that the node receives the disconnect request by the ip interface and it must obey. Unfortunately, no further explanation is given by the Gewiss knx ip interface. The .json persistent files are bornt with knx ultimate. Such procedure of saving statuses exists since years. Do you remember what was the previous knx ultimate version you had installed, knowing to be working fine?

gtnscebba commented 2 weeks ago

I remember 3.2.14, maybe.

How to do the downgrade?

Supergiovane commented 2 weeks ago

Thanks for the donation! Cd into your .node-red folder and issue: npm install node-red-contrib-knx-ultimate@3.2.14

gtnscebba commented 2 weeks ago

Done. I'll monitor the system. It's a pleasure to have donated: your project is superb and the support is unmatched.

gtnscebba commented 2 weeks ago

An update. Almost 40-45 minutes after a NodeRed restart, on journal there are the messages:

Nov 11 11:15:48 PI4 Node-RED[4167]: 11/11/2024, 11:15:48 [KNXEngine] [ERROR] KNXClient: into async closeSocket(): Error: Not running
Nov 11 11:15:48 PI4 Node-RED[4167]:     at healthCheck (node:dgram:924:11)
Nov 11 11:15:48 PI4 Node-RED[4167]:     at Socket.close (node:dgram:749:3)
Nov 11 11:15:48 PI4 Node-RED[4167]:     at /home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1130:41
Nov 11 11:15:48 PI4 Node-RED[4167]:     at new Promise (<anonymous>)
Nov 11 11:15:48 PI4 Node-RED[4167]:     at KNXClient.closeSocket (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1116:10)
Nov 11 11:15:48 PI4 Node-RED[4167]:     at KNXClient.Disconnect (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1165:15)
Nov 11 11:15:48 PI4 Node-RED[4167]:     at knxUltimateConfigNode.node.initKNXConnection (/home/pi/.node-red/node_modules/node-red-contrib-knx-ultimate/nodes/knxUltimate-config.js:618:38)
Nov 11 11:16:04 PI4 Node-RED[4167]: 11/11/2024, 11:16:04 [KNXEngine] [ERROR] Received KNX packet: DISCONNECT_REQUEST, ChannelID:159 Host:192.168.1.200:3671
Nov 11 11:16:05 PI4 Node-RED[4167]: 11/11/2024, 11:16:05 [KNXEngine] [ERROR] Sending KNX packet: Send UDP Catch error: Not running object seqCounter:9
Nov 11 11:16:05 PI4 Node-RED[4167]: 11/11/2024, 11:16:05 [KNXEngine] [ERROR] Error: Not running
Nov 11 11:16:05 PI4 Node-RED[4167]:     at healthCheck (node:dgram:924:11)
Nov 11 11:16:05 PI4 Node-RED[4167]:     at Socket.send (node:dgram:651:3)
Nov 11 11:16:05 PI4 Node-RED[4167]:     at KNXClient.processKnxPacketQueueItem (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:501:40)
Nov 11 11:16:05 PI4 Node-RED[4167]:     at KNXClient.handleKNXQueue (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:561:16)
Nov 11 11:16:05 PI4 Node-RED[4167]: 11/11/2024, 11:16:05 [knxUltimate-config <Casa>] [ERROR] received KNXClientEvents.error: Not running
Nov 11 11:16:05 PI4 Node-RED[4167]: 11/11/2024, 11:16:05 [knxUltimate-config <Casa>] [ERROR] Disconnected by: Not running
Nov 11 11:16:10 PI4 Node-RED[4167]: 11/11/2024, 11:16:10 [KNXEngine] [ERROR] KNXClient: into async closeSocket(): Error: Not running
Nov 11 11:16:10 PI4 Node-RED[4167]:     at healthCheck (node:dgram:924:11)
Nov 11 11:16:10 PI4 Node-RED[4167]:     at Socket.close (node:dgram:749:3)
Nov 11 11:16:10 PI4 Node-RED[4167]:     at /home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1130:41
Nov 11 11:16:10 PI4 Node-RED[4167]:     at new Promise (<anonymous>)
Nov 11 11:16:10 PI4 Node-RED[4167]:     at KNXClient.closeSocket (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1116:10)
Nov 11 11:16:10 PI4 Node-RED[4167]:     at KNXClient.Disconnect (/home/pi/.node-red/node_modules/knxultimate/src/KNXClient.ts:1165:15)
Nov 11 11:16:10 PI4 Node-RED[4167]:     at knxUltimateConfigNode.node.initKNXConnection (/home/pi/.node-red/node_modules/node-red-contrib-knx-ultimate/nodes/knxUltimate-config.js:618:38)
^C
Supergiovane commented 2 weeks ago

If you have another RPI or if you can setup a VM, you could try with a fresh install. More than that, i unfortunately cannot do from here. As for your pace of mind, no other users reported such issue and my system at home also runs flawlessly.

Nov 11 11:16:04 PI4 Node-RED[4167]: 11/11/2024, 11:16:04 [KNXEngine] [ERROR] Received KNX packet: **DISCONNECT_REQUEST**, ChannelID:159 Host:192.168.1.200:3671
Nov 11 11:16:05 PI4 Node-RED[4167]: 11/11/2024, 11:16:05 [KNXEngine] [ERROR] Sending KNX packet: Send UDP Catch error: Not running object **seqCounter:9**

The seqCounter:9 states that the number of exchanged telegrams before the disconnection is 9, that means that the Gewiss, kicks you off soon after the connection request. Do you only have the Gewiss to test with?

Supergiovane commented 2 weeks ago

PS: in the advanced tab, you could try to increase the delay between telegrams to, for example 150ms and see what happens.

gtnscebba commented 2 weeks ago

Do you only have the Gewiss to test with?

I've tried another Gateway (a Siemens) and the error is the same.

PS: in the advanced tab, you could try to increase the delay between telegrams to, for example 150ms and see what happens.

I've increased at 150ms, the behaviour is the same

Supergiovane commented 2 weeks ago

Restarted Node-Red? What siemens? I ask, because 80% of the gateways are re-branded ones, so i's probably, that both are the same :-)

gtnscebba commented 2 weeks ago

Siemens N350E

Yes, I restarted NodeRed.

Supergiovane commented 2 weeks ago

Hi please set the debug level to "debug" and post the log again. We need to address this problem.

gtnscebba commented 2 weeks ago

I have issued the new level. 

Nov 11 13:48:39 PI4 Node-RED[12403]: 11/11/2024, 13:48:39 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 0 1057
Nov 11 13:48:39 PI4 Node-RED[12403]: 11/11/2024, 13:48:39 [KNXEngine] [DEBUG] Received KNX packet: _processInboundMessage, Data received: 06100420001704ca0a002900bce0110e100203008018f2 srcAddress: {"address":"192.168.1.200","family":"IPv4","port":3671,"size":23} ChannelID:202
Nov 11 13:48:39 PI4 Node-RED[12403]: 11/11/2024, 13:48:39 [KNXEngine] [DEBUG] KNXClient: ADDED TELEGRAM TO COMMANDQUEUE. Len: 1, Priority: true {"knxPacket":{"type":1057,"length":4,"_header":{"_headerLength":6,"_version":16,"service_type":1057,"length":10},"channelID":202,"seqCounter":10,"status":0},"expectedSeqNumberForACK":5}
Nov 11 13:48:39 PI4 Node-RED[12403]: 11/11/2024, 13:48:39 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: L_DATA_IND, Data: {"_tpci":0,"_apci":128,"_data":{"_data":{"type":"Buffer","data":[24,242]}}} srcAddress: 1.1.14 dstAddress: 2/0/2 ChannelID:202 seqCounter:10 Host:192.168.1.200:3671
Nov 11 13:48:40 PI4 Node-RED[12403]: 11/11/2024, 13:48:40 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 0 1057
Nov 11 13:48:58 PI4 Node-RED[12403]: 11/11/2024, 13:48:58 [KNXEngine] [DEBUG] Received KNX packet: _processInboundMessage, Data received: 06100420001804ca0b002900bce011011a000400802d3100 srcAddress: {"address":"192.168.1.200","family":"IPv4","port":3671,"size":24} ChannelID:202
Nov 11 13:48:58 PI4 Node-RED[12403]: 11/11/2024, 13:48:58 [KNXEngine] [DEBUG] KNXClient: ADDED TELEGRAM TO COMMANDQUEUE. Len: 1, Priority: true {"knxPacket":{"type":1057,"length":4,"_header":{"_headerLength":6,"_version":16,"service_type":1057,"length":10},"channelID":202,"seqCounter":11,"status":0},"expectedSeqNumberForACK":5}
Nov 11 13:48:58 PI4 Node-RED[12403]: 11/11/2024, 13:48:58 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: L_DATA_IND, Data: {"_tpci":0,"_apci":128,"_data":{"_data":{"type":"Buffer","data":[45,49,0]}}} srcAddress: 1.1.1 dstAddress: 3/2/0 ChannelID:202 seqCounter:11 Host:192.168.1.200:3671
Nov 11 13:48:59 PI4 Node-RED[12403]: 11/11/2024, 13:48:59 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 0 1057
Nov 11 13:48:59 PI4 Node-RED[12403]: 11/11/2024, 13:48:59 [KNXEngine] [DEBUG] Received KNX packet: _processInboundMessage, Data received: 06100420001804ca0c002900bce011011a010400800b0b18 srcAddress: {"address":"192.168.1.200","family":"IPv4","port":3671,"size":24} ChannelID:202
Nov 11 13:48:59 PI4 Node-RED[12403]: 11/11/2024, 13:48:59 [KNXEngine] [DEBUG] KNXClient: ADDED TELEGRAM TO COMMANDQUEUE. Len: 1, Priority: true {"knxPacket":{"type":1057,"length":4,"_header":{"_headerLength":6,"_version":16,"service_type":1057,"length":10},"channelID":202,"seqCounter":12,"status":0},"expectedSeqNumberForACK":5}
Nov 11 13:48:59 PI4 Node-RED[12403]: 11/11/2024, 13:48:59 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: L_DATA_IND, Data: {"_tpci":0,"_apci":128,"_data":{"_data":{"type":"Buffer","data":[11,11,24]}}} srcAddress: 1.1.1 dstAddress: 3/2/1 ChannelID:202 seqCounter:12 Host:192.168.1.200:3671
Nov 11 13:49:00 PI4 Node-RED[12403]: 11/11/2024, 13:49:00 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 0 1057
Nov 11 13:49:01 PI4 Node-RED[12403]: 11/11/2024, 13:49:01 [KNXEngine] [DEBUG] Received KNX packet: _processInboundMessage, Data received: 06100420001804ca0d002900bce000ff1a010400800b0b18 srcAddress: {"address":"192.168.1.200","family":"IPv4","port":3671,"size":24} ChannelID:202
Nov 11 13:49:01 PI4 Node-RED[12403]: 11/11/2024, 13:49:01 [KNXEngine] [DEBUG] KNXClient: ADDED TELEGRAM TO COMMANDQUEUE. Len: 1, Priority: true {"knxPacket":{"type":1057,"length":4,"_header":{"_headerLength":6,"_version":16,"service_type":1057,"length":10},"channelID":202,"seqCounter":13,"status":0},"expectedSeqNumberForACK":5}
Nov 11 13:49:01 PI4 Node-RED[12403]: 11/11/2024, 13:49:01 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: L_DATA_IND, Data: {"_tpci":0,"_apci":128,"_data":{"_data":{"type":"Buffer","data":[11,11,24]}}} srcAddress: 0.0.255 dstAddress: 3/2/1 ChannelID:202 seqCounter:13 Host:192.168.1.200:3671
Nov 11 13:49:02 PI4 Node-RED[12403]: 11/11/2024, 13:49:02 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 0 1057
Nov 11 13:49:02 PI4 Node-RED[12403]: 11/11/2024, 13:49:02 [KNXEngine] [DEBUG] Received KNX packet: _processInboundMessage, Data received: 06100420001804ca0e002900bce000ff1a000400802d3101 srcAddress: {"address":"192.168.1.200","family":"IPv4","port":3671,"size":24} ChannelID:202
Nov 11 13:49:02 PI4 Node-RED[12403]: 11/11/2024, 13:49:02 [KNXEngine] [DEBUG] KNXClient: ADDED TELEGRAM TO COMMANDQUEUE. Len: 1, Priority: true {"knxPacket":{"type":1057,"length":4,"_header":{"_headerLength":6,"_version":16,"service_type":1057,"length":10},"channelID":202,"seqCounter":14,"status":0},"expectedSeqNumberForACK":5}
Nov 11 13:49:02 PI4 Node-RED[12403]: 11/11/2024, 13:49:02 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: L_DATA_IND, Data: {"_tpci":0,"_apci":128,"_data":{"_data":{"type":"Buffer","data":[45,49,1]}}} srcAddress: 0.0.255 dstAddress: 3/2/0 ChannelID:202 seqCounter:14 Host:192.168.1.200:3671
Nov 11 13:49:03 PI4 Node-RED[12403]: 11/11/2024, 13:49:03 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 0 1057

Since one hour the problem is NOT occurred.

I'll disable it now and put it back at debug level when the problem occurs again.

gtnscebba commented 2 weeks ago

I'll using 3.2.15.

In this moment the proble is occured, this is the debug log:

Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: TUNNELING_ACK, ChannelID:206 seqCounter:3 Host:192.168.1.200:3671
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: _processInboundMessage, Data received: 06100420001504ce03002900bce0ff162a02010000 srcAddress: {"address":"192.168.1.200","family":"IPv4","port":3671,"size":21} ChannelID:206
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] KNXClient: ADDED TELEGRAM TO COMMANDQUEUE. Len: 3, Priority: true {"knxPacket":{"type":1057,"length":4,"_header":{"_headerLength":6,"_version":16,"service_type":1057,"length":10},"channelID":206,"seqCounter":3,"status":0},"expectedSeqNumberForACK":5}
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: L_DATA_IND, Data: {"_tpci":0,"_apci":0,"_data":null} srcAddress: 15.15.22 dstAddress: 5/2/2 ChannelID:206 seqCounter:3 Host:192.168.1.200:3671
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 2 1057
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 1 1056
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Sending KNX packet: KNXTunnelingRequest Data: {"_tpci":0,"_apci":0,"_data":null} srcAddress: 15.15.22 dstAddress: 5/2/22 Host:192.168.1.200:3671 channelID:206 seqCounter:4 Dest:5/2/22  Data:00 TPCI:Read
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: _processInboundMessage, Data received: 06100421000a04ce0400 srcAddress: {"address":"192.168.1.200","family":"IPv4","port":3671,"size":10} ChannelID:206
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: TUNNELING_ACK, ChannelID:206 seqCounter:4 Host:192.168.1.200:3671
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: _processInboundMessage, Data received: 06100420001504ce04002900bce0ff162a16010000 srcAddress: {"address":"192.168.1.200","family":"IPv4","port":3671,"size":21} ChannelID:206
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] KNXClient: ADDED TELEGRAM TO COMMANDQUEUE. Len: 2, Priority: true {"knxPacket":{"type":1057,"length":4,"_header":{"_headerLength":6,"_version":16,"service_type":1057,"length":10},"channelID":206,"seqCounter":4,"status":0},"expectedSeqNumberForACK":5}
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: L_DATA_IND, Data: {"_tpci":0,"_apci":0,"_data":null} srcAddress: 15.15.22 dstAddress: 5/2/22 ChannelID:206 seqCounter:4 Host:192.168.1.200:3671
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 1 1057
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 0 1056
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Sending KNX packet: KNXTunnelingRequest Data: {"_tpci":0,"_apci":0,"_data":null} srcAddress: 15.15.22 dstAddress: 5/2/1 Host:192.168.1.200:3671 channelID:206 seqCounter:5 Dest:5/2/1  Data:00 TPCI:Read
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: _processInboundMessage, Data received: 06100421000a04ce0500 srcAddress: {"address":"192.168.1.200","family":"IPv4","port":3671,"size":10} ChannelID:206
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: TUNNELING_ACK, ChannelID:206 seqCounter:5 Host:192.168.1.200:3671
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: _processInboundMessage, Data received: 06100420001504ce05002900bce0ff162a01010000 srcAddress: {"address":"192.168.1.200","family":"IPv4","port":3671,"size":21} ChannelID:206
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] KNXClient: ADDED TELEGRAM TO COMMANDQUEUE. Len: 1, Priority: true {"knxPacket":{"type":1057,"length":4,"_header":{"_headerLength":6,"_version":16,"service_type":1057,"length":10},"channelID":206,"seqCounter":5,"status":0},"expectedSeqNumberForACK":5}
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] Received KNX packet: TUNNELING: L_DATA_IND, Data: {"_tpci":0,"_apci":0,"_data":null} srcAddress: 15.15.22 dstAddress: 5/2/1 ChannelID:206 seqCounter:5 Host:192.168.1.200:3671
Nov 11 14:54:17 PI4 Node-RED[12403]: 11/11/2024, 14:54:17 [KNXEngine] [DEBUG] KNXClient: processKnxPacketQueueItem: Processing queued KNX. commandQueue.length: 0 1057
gtnscebba commented 2 weeks ago

I have issued this command to obtain the error on a file:

journalctl -f | grep KNXEngine > knxerrors.txt

The file is attached.

knxerrors.txt

Supergiovane commented 2 weeks ago

Hi, can you please post the full log? Not only the error or debug portion. Thanks.

gtnscebba commented 2 weeks ago

This is the full log.

knxerrors.txt

gtnscebba commented 2 weeks ago

I have configured some KNXUltimate nodes (devices) that use a connection with the Siemens Gateway and others with the Gewiss Gateway. I restarted NodeRed and at the moment there are no errors, both work simultaneously. Since the errors arrive after a certain time (> 45 minutes) can't it be some memory leak inside the KNXUltimate palette?

Supergiovane commented 2 weeks ago

Hi Gaetano can you please unzip this file into your .node-red/node_modules/node-red-contrib-knx-ultimate/nodes folder and restart node-red?

Archivio.zip

Supergiovane commented 2 weeks ago

I have configured some KNXUltimate nodes (devices) that use a connection with the Siemens Gateway and others with the Gewiss Gateway. I restarted NodeRed and at the moment there are no errors, both work simultaneously. Since the errors arrive after a certain time (> 45 minutes) can't it be some memory leak inside the KNXUltimate palette?

All nodes i developed, take very a serious approach to memory and CPU usage. There are lot of installers/professionals with months (some even years) of uptime. You'll never have memory leakage coming from my "ultimate" nodes :-)

gtnscebba commented 2 weeks ago

Hi Gaetano can you please unzip this file into your .node-red/node_modules/node-red-contrib-knx-ultimate/nodes folder and restart node-red?

Done. I restarted NodeRed. I've seen tht the palette version is stil 3.2.15: is it correct? NodeRed version is 4.0.5...

gtnscebba commented 2 weeks ago

I've upgraded palette to 3.2.17, and (after) copied the new modules (3)

Supergiovane commented 2 weeks ago

Perfect. We'll see. Please let me know

gtnscebba commented 2 weeks ago

It's still running. The log is at "Error" level. Do you want "Debug"?

Supergiovane commented 2 weeks ago

Nope. Not for now.

gtnscebba commented 2 weeks ago

After a few hours of restarting NodeRed and installing the 3 new modules, everything is working fine. For now, thanks Massimo!

gtnscebba commented 2 weeks ago

Sorry, Massimo, but this morning I've seen that the error is still present. Attached you'll find the new journal log (with debug level for KNXUltimate).

knxerrors.txt

Supergiovane commented 2 weeks ago

Hi ok, let do some hacks. Please do the same as prevoius with this file.

knxUltimate-config.js.zip