node-red-contrib-homekit-bridged icon indicating copy to clipboard operation
node-red-contrib-homekit-bridged copied to clipboard

[Bug]: High and increasing CPU usage over time

Open MicheleSilla810 opened this issue 2 years ago • 20 comments

NRCHKB Plugin Version

1.4.3

Node JS Version

3.0.2 Node-RED Container

NPM Version

3.0.2 Node-RED Container

Node-RED Version

3.0.2

Operating System

Docker

What happened?

The CPU usage of Node-RED is super high, and incresaing day by day. It happened 2 times that it reached a point where Node-RED was running 5 seconds late on every message, and CPU usage was pinned at 100%. I traced down the issue, and it's NRCHKB. Never had this issue, and I don't precisely know when it started. Probably did a palette update, but din't pay attention to what version i was running before. The flows haven't changed.

I restarted Node-RED yesterday evening, and it was at 25% usage. It now was at 50%, so i tried disabling the bridge configuration nodes, and the usage went down to 0%. Then i re-enabled the bridges and the usage went up to ~25%. Here a pic during this process. Node-RED stats in portainer image

I checked all NRCHKB nodes to see if maybe something is spamming messages in the nodes, but it's all OK. The strange thing i think is the fact that the usage keeps increasing and increasing, up to a point where Node-RED becomes so slow that it needs a restart.

I'm running on a Pi 4B, under docker

Is this a known behavior? Thanks!

How to reproduce?

Nothing particular

Expected behavior:

Describe expected behavior here, with relevant screenshots if they would help.

Additional comments?

Additional comments here, if any.

Relevant log output

There are no logs from NRCHKB in Node-RED logs.

MicheleSilla810 avatar Oct 31 '22 09:10 MicheleSilla810

Hey, behaviour is unknown to me. Running node for years and have never seen it.

Can you tell me more about the setup?

Shaquu avatar Oct 31 '22 10:10 Shaquu

Yes I have 4 bridges. One is used by 4 humidity sensor accessories One is used by 7 light bulb accessories One is used by 4 thermostat accessories One is used by 31 various accessories (thermostats, heater coolers, light bulbs, water valve, fans) All of them have CIAO advertising. This setup is running as-is for about 1.5 years without edits. Until like 1 month ago when i updated NRCHKB and Node-RED Tried disabling them one by one, but didn't seem to make a difference, until i disabled all 4.

Just thought, could it be iOS devices and HomePods pinging the bridges for some reason? But i feel like that wouldn't explain why the usage keeps increasing every day Could it also be a Node-RED 3 issue?

Here i attach a screenshot of the usage when disabling the bridges one by one. The peaks are the deployments image I also have 5 billiond nodes, but as you can see, without HK conf. nodes activated the usage goes to 0, so those are not the root cause i think. Could you check on your instances if the usage goes drasticly down when disabling all HK conf. nodes?

IDK what other info to provide, let me know

Thanks

MicheleSilla810 avatar Oct 31 '22 10:10 MicheleSilla810

What about machine specs?

Shaquu avatar Oct 31 '22 11:10 Shaquu

Pi 4B 4GB, running Node-RED under docker Always 2/2.5GB of free ram, machine cpu usage normally is at ~4%, with HK activated it's 25% base, and increasing

MicheleSilla810 avatar Oct 31 '22 12:10 MicheleSilla810

Running on docker compose (pi4 4gb) image

Running as a process (pi4 8gb) image

Shaquu avatar Oct 31 '22 13:10 Shaquu

HK enabled image

HK disabled image

don't really know what else to say

MicheleSilla810 avatar Oct 31 '22 13:10 MicheleSilla810

To me sounds like an infinity loop. Do you have a backup before you added nrchkb to your setup? If so maybe restore that and then try some of our example flows and see if it behaves the same?

caitken-com avatar Oct 31 '22 23:10 caitken-com

no i can guarantee that is not the case, because as i said, i manually checked every input and output of the nrchkb nodes, and there is nothing wrong, no spam or looping messages. also as i said, i’ve been running this setup without any modifications for 1.5 years. this is a new thing after i updated nrchkb to 1.4.3 and Node-RED to 3.0.2. so i think it’s either one, or the other, or the combination of both.

MicheleSilla810 avatar Nov 01 '22 07:11 MicheleSilla810

Did you do a clean install of both NR & nrchkb? If not, that would be my next step to make sure some old config or cache isn’t causing issues. How long did you need to run NR to see the cpu/ram spike?

I’m running same the versions but not in docker, on a pi4. CB541255-776E-4B92-9AF0-0B8464859093

caitken-com avatar Nov 01 '22 23:11 caitken-com

Tried creating a new fresh container, and i found out that

Node-RED 3.0.2: image image same thing as the other instance, when deploying the usage goes and stays up, when removing and re-deploying, the usage goes back to 0

So i tried creating a new container with instead Node-RED 2.2.2: image image The two peaks are the 2 deployments, and between them when nrchkb was active, there is 0 usage

So i think, as i said initially, that the cause could be NR 3.0 So, in your setups, are you running 3.x or 2.x?

MicheleSilla810 avatar Nov 02 '22 09:11 MicheleSilla810

I am on version 3. Do you mind to share your flow?

Shaquu avatar Nov 02 '22 09:11 Shaquu

[ { "id": "bd3b068d9f32d7cc", "type": "homekit-service", "z": "d9a7a19c.5d00e", "isParent": true, "hostType": "0", "bridge": "a746d8b451ae08ea", "accessoryId": "", "parentService": "", "name": "jhjhkj", "serviceName": "AirQualitySensor", "topic": "", "filter": false, "manufacturer": "NRCHKB", "model": "1.4.3", "serialNo": "Default Serial Number", "firmwareRev": "1.4.3", "hardwareRev": "1.4.3", "softwareRev": "1.4.3", "cameraConfigVideoProcessor": "ffmpeg", "cameraConfigSource": "", "cameraConfigStillImageSource": "", "cameraConfigMaxStreams": 2, "cameraConfigMaxWidth": 1280, "cameraConfigMaxHeight": 720, "cameraConfigMaxFPS": 10, "cameraConfigMaxBitrate": 300, "cameraConfigVideoCodec": "libx264", "cameraConfigAudioCodec": "libfdk_aac", "cameraConfigAudio": false, "cameraConfigPacketSize": 1316, "cameraConfigVerticalFlip": false, "cameraConfigHorizontalFlip": false, "cameraConfigMapVideo": "0:0", "cameraConfigMapAudio": "0:1", "cameraConfigVideoFilter": "scale=1280:720", "cameraConfigAdditionalCommandLine": "-tune zerolatency", "cameraConfigDebug": false, "cameraConfigSnapshotOutput": "disabled", "cameraConfigInterfaceName": "", "characteristicProperties": "{}", "waitForSetupMsg": false, "outputs": 2, "x": 370, "y": 700, "wires": [ [], [] ] }, { "id": "a746d8b451ae08ea", "type": "homekit-bridge", "bridgeName": "lklk", "pinCode": "876-03-943", "port": "", "advertiser": "ciao", "allowInsecureRequest": false, "manufacturer": "NRCHKB", "model": "1.4.3", "serialNo": "Default Serial Number", "firmwareRev": "1.4.3", "hardwareRev": "1.4.3", "softwareRev": "1.4.3", "customMdnsConfig": false, "mdnsMulticast": true, "mdnsInterface": "", "mdnsPort": "", "mdnsIp": "", "mdnsTtl": "", "mdnsLoopback": true, "mdnsReuseAddr": true, "allowMessagePassthrough": true } ]

MicheleSilla810 avatar Nov 02 '22 09:11 MicheleSilla810

NR 3.0.2 NRCHKB: 1.4.3 But I don’t run in docker. It’s a Pi4, has 1 job to run NR 🤷‍♂️

caitken-com avatar Nov 04 '22 00:11 caitken-com

little update i completely re-did the setup, i also istalled raspberry pi os 64bit (i was on 32 bit before) aaand, still the same exact issue. still node-red 3.0.2, 8 days of runtime image and still, if i disable nrchkb, the usage goes to absolute 0.

MicheleSilla810 avatar Nov 12 '22 18:11 MicheleSilla810

here's a container restart image

MicheleSilla810 avatar Nov 12 '22 18:11 MicheleSilla810

same problem after updating 1.4.x -> 1.5.0, no new scripts or changes

NR 3.0.2, intel nuc, 8gb ram, but NR is almost dead after 2-3 days, high cpu load

only restart nodered.service can help for a few days

how to debug this?

ptath avatar Dec 09 '22 18:12 ptath

First of all, you can run nodered with debug mode. DEBUG=* We should have some time stamps and action logs which we can correlate.

Shaquu avatar Dec 09 '22 20:12 Shaquu

OK, reverted to 1.4.3 but still have a problem.

And it looks like a different problem. Sometimes pressing a button in a home.app (on any device, even ATV in local wifi) causes a 3-10 sec hanging before a "signal" is caught by NR node.

Direct inject/debug works immediately, but home.app (and all it automations of course) clicks makes it hangs sometimes.

https://idiod.video/v14knh.mp4 — you can notice a circle sometimes after clicking

Rebooting, restarting and so on, no idea even how to start to debug this. No trails in NR logs, looks like it just delaying commands sometimes.

ptath avatar Dec 17 '22 15:12 ptath

I don’t use Docker so might be unrelated. But what Advertiser are you using on your NRCHKB config node(s)? Is docker networking in Host mode? And check that the Advertiser’s port is open/not shared by another service.

caitken-com avatar Dec 18 '22 19:12 caitken-com

@ptath where did you get with this?

caitken-com avatar Aug 15 '23 22:08 caitken-com

Closing as no update from author.

Please do upgrade all components whenever possible, including:

  • node-red
  • Node.js
  • nrchkb
  • iOS

Feel free to open a new issue once you have new data!

Shaquu avatar Jun 15 '24 22:06 Shaquu