Describe The Bug: Plugin memory increase steadily over time. Ove

Ping is every <a href="https://github.com/thenewwazoo/lutron-leap-js/blob/main/src/Sma

Memory Leak about homebridge-lutron-caseta-leap HOT 30 CLOSED

thenewwazoo commented on July 19, 2024

Memory Leak

from homebridge-lutron-caseta-leap.

Comments (30)

thenewwazoo commented on July 19, 2024

Man that's super duper weird, I don't observe the same thing. I'm running the same versions of the whole stack.

How much are you using the plugin, i.e. how many button presses would have occurred during the sample period? Do you observe any CPU usage by the plugin even when inactive? If you could turn on debug logging (see the readme for that), that would be a great help. Specifically, I'd be interested to see if pings are happening strangely, if there are any timeouts or client flapping, or if your bridge is being improperly re-detected repeatedly.

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

I would say the button presses are not all that common, a few a day maybe.
I can turn on debug and leave it running then pull logs tomorrow. My CPU usage seems stable.

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

Great, thank you. Just thinking out loud, the only non-user-initiated actions that happen on a recurring schedule are server pings and bridge announcements (and those are largely ignored). Client disconnects could cause churn, but I feel like you'd have noticed the client connection dying repeatedly.

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

How often should the ping occur?

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

So this seems ominous… I just noticed my remotes vanished from HomeKit. Restarting doesn’t restore them, but removing from HB cache and restarting does. Nothing crazy in the logs though.

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

O_o

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

Ping is every 60 seconds. Bridges re-announce like once a day or so, I think?

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

I am as baffled by the remotes disappearing altogether, and being restored by deleting cache, as I am by the memory leak.

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

Did the cache refresh solve the issue or has it recurred?

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

That is interesting, because after I had to nuke the plugin and started over the memory usage has not been as high and the leak has not been as severe. Still over the last 24 hours It has increased 9%.

Here are the logs from before I had to clear the cache.
leaplog.txt

Here are the logs post-cache clear, which seem cleaner. I included a restart at the end to compare the two and there are some minor differences, but nothing that seems like a problem. You may have a more discerning eye here.
leaplog3.txt

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

So a few days later and the memory leak is quite prominent again.

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

The only, only thing I notice that's even the tiniest bit weird is that the log has gaps in it, e.g. from leaplog.txt, lines 7-8, 892-893, 1180-1181. There are multi-hour gaps there but, like, maybe that's the oomkiller or something.

I am totally baffled by this, unfortunately. I'm looking into how to get heap dumps out of nodejs, and hopefully will be able to instruct you on how to get before/after dumps that I can look at.

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

I saw the update. I’ll wait for instructions on how to do the dump.

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

After you find the plug-in process, run kill -SIGUSR2 followed by the processs id. Do this right after a restart and then after ram usage grows large. I’ll want both heap dumps.

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

~~Any idea where this dumps to? I can't find the output.~~
I see the direction in the logs now.

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

Alright, here are two heap dumps. I hope this gives us something to go off of.

Taken at service startup:
lutron.1644283453521.heapsnapshot.txt
Taken after severe memory loss and right before a crash:
lutron.1644327823089.heapsnapshot.txt

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

I took a look at both dumps, and they don't appear to show huge memory usage.

The first one reflects 12 MB, and the second 14.5 MB, heap usage, which is... not much.

As a point of comparison, this is my homebridge instance, recently restarted, that has a few more devices (including one in beta).

Can you provide more info or tracing information? I'm afraid I've hit a dead end.

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

What is the heap dump capturing for exactly, like is it only JS memory or limited in some other way? It’s weird because in my tracking I know the plugin has reached like 200 MB regularly, 230 MB being the highest I’ve seen it go. So way more than 12 or 14, and that’s just the top thread. It usually has several threads in use.

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

A heap dump lists all the objects in memory that the JS runtime knows about. Basically, every piece of memory that Node has allocated that is either in use, or scheduled to be collected/cleaned up.

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

Alright, I just took another dump. Before this I checked the memory of the plugin, which was 184.7 MB.
Here is the output from the pmap.

14049:   homebridge: homebridge-lutron-caseta-leap                                                                     
00010000  60552K r-x-- node
03b41000      8K r---- node
03b43000     60K rw--- node
03b52000    104K rw---   [ anon ]
04198000  12968K rw---   [ anon ]
201c0000    256K rw---   [ anon ]
205c0000    256K rw---   [ anon ]
206c0000    256K rw---   [ anon ]
20c80000    256K rw---   [ anon ]
20dc0000    256K rw---   [ anon ]
210c0000     12K rw---   [ anon ]
210c3000      4K -----   [ anon ]
210c4000    236K r-x--   [ anon ]
210ff000      4K -----   [ anon ]
21ac0000    256K rw---   [ anon ]
21c80000    256K rw---   [ anon ]
23940000     52K rw---   [ anon ]
25100000    256K rw---   [ anon ]
273c0000     12K rw---   [ anon ]
273c3000      4K -----   [ anon ]
273c4000    236K r-x--   [ anon ]
273ff000      4K -----   [ anon ]
27bc0000    256K rw---   [ anon ]
28480000    256K -----   [ anon ]
29240000    256K rw---   [ anon ]
29540000    256K rw---   [ anon ]
29b00000    256K rw---   [ anon ]
29d80000     12K rw---   [ anon ]
29d83000      4K -----   [ anon ]
29d84000    236K r-x--   [ anon ]
29dbf000      4K -----   [ anon ]
29f80000    256K rw---   [ anon ]
2a340000     12K rw---   [ anon ]
2a343000      4K -----   [ anon ]
2a344000     64K r-x--   [ anon ]
2a354000      4K -----   [ anon ]
2a540000    256K rw---   [ anon ]
2abc0000    256K rw---   [ anon ]
2ae00000    256K rw---   [ anon ]
2c640000    256K rw---   [ anon ]
2d780000    256K rw---   [ anon ]
2d840000    256K rw---   [ anon ]
2d940000    256K -----   [ anon ]
2dc00000    256K rw---   [ anon ]
2fb80000    256K rw---   [ anon ]
30600000    256K -----   [ anon ]
31e00000    256K -----   [ anon ]
32000000    256K rw---   [ anon ]
33300000     12K rw---   [ anon ]
33303000      4K -----   [ anon ]
33304000    236K r-x--   [ anon ]
3333f000      4K -----   [ anon ]
35ac0000    256K rw---   [ anon ]
363c0000    256K rw---   [ anon ]
36c40000    256K -----   [ anon ]
37200000    256K rw---   [ anon ]
37780000     12K rw---   [ anon ]
37783000      4K -----   [ anon ]
37784000    236K r-x--   [ anon ]
377bf000      4K -----   [ anon ]
38300000    256K rw---   [ anon ]
383c0000    256K rw---   [ anon ]
39f40000     12K rw---   [ anon ]
39f43000      4K -----   [ anon ]
39f44000    236K r-x--   [ anon ]
39f7f000      4K -----   [ anon ]
3a080000    268K rw---   [ anon ]
3a0c3000      4K -----   [ anon ]
3a0c4000    236K r-x--   [ anon ]
3a0ff000      4K -----   [ anon ]
3ad40000    256K rw---   [ anon ]
3b080000    256K rw---   [ anon ]
3b640000    256K rw---   [ anon ]
3bb80000    256K rw---   [ anon ]
3bc80000    256K rw---   [ anon ]
3d000000    256K rw---   [ anon ]
3dc00000    256K rw---   [ anon ]
3eb40000    512K rw---   [ anon ]
3ed00000    256K -----   [ anon ]
3ee80000    256K rw---   [ anon ]
402c0000    256K rw---   [ anon ]
405c0000    256K rw---   [ anon ]
40b00000    256K rw---   [ anon ]
40cc0000     12K rw---   [ anon ]
40cc3000      4K -----   [ anon ]
40cc4000    236K r-x--   [ anon ]
40cff000      4K -----   [ anon ]
410c0000    256K rw---   [ anon ]
411c0000    256K rw---   [ anon ]
41b40000    256K rw---   [ anon ]
42100000    256K rw---   [ anon ]
43000000    256K rw---   [ anon ]
43080000    256K rw---   [ anon ]
43680000    256K -----   [ anon ]
43700000     12K rw---   [ anon ]
43703000      4K -----   [ anon ]
43704000    236K r-x--   [ anon ]
4373f000      4K -----   [ anon ]
43e40000    256K -----   [ anon ]
44880000    256K rw---   [ anon ]
45280000    256K rw---   [ anon ]
45780000    256K rw---   [ anon ]
47000000     12K rw---   [ anon ]
47003000      4K -----   [ anon ]
47004000    236K r-x--   [ anon ]
4703f000      4K -----   [ anon ]
47840000     12K rw---   [ anon ]
47843000      4K -----   [ anon ]
47844000    236K r-x--   [ anon ]
4787f000      4K -----   [ anon ]
47cc0000    256K rw---   [ anon ]
49f80000    256K rw---   [ anon ]
4b100000    256K rw---   [ anon ]
4b940000    256K rw---   [ anon ]
4bb80000    256K rw---   [ anon ]
4c300000    256K -----   [ anon ]
4c680000     12K rw---   [ anon ]
4c683000      4K -----   [ anon ]
4c684000    236K r-x--   [ anon ]
4c6bf000      4K -----   [ anon ]
4cd40000    256K rw---   [ anon ]
4d340000    256K rw---   [ anon ]
4de80000    136K r----   [ anon ]
4f6c0000    256K -----   [ anon ]
50200000    256K rw---   [ anon ]
513c0000    256K -----   [ anon ]
51b40000    256K rw---   [ anon ]
51f80000    256K rw---   [ anon ]
522c0000    256K rw---   [ anon ]
53d40000     12K rw---   [ anon ]
53d43000      4K -----   [ anon ]
53d44000    236K r-x--   [ anon ]
53d7f000      4K -----   [ anon ]
54000000    228K rw---   [ anon ]
54100000    256K rw---   [ anon ]
549c0000    256K -----   [ anon ]
54f00000    256K rw---   [ anon ]
557c0000    256K rw---   [ anon ]
559c0000    256K rw---   [ anon ]
55f40000    256K rw---   [ anon ]
56140000    256K rw---   [ anon ]
56c00000    256K rw---   [ anon ]
56d00000    256K rw---   [ anon ]
58540000    256K -----   [ anon ]
59340000    256K rw---   [ anon ]
5a9c0000    256K rw---   [ anon ]
5c640000    256K rw---   [ anon ]
5cec0000    256K rw---   [ anon ]
5d380000    256K -----   [ anon ]
5d780000     12K rw---   [ anon ]
5d783000      4K -----   [ anon ]
5d784000    236K r-x--   [ anon ]
5d7bf000      4K -----   [ anon ]
5d940000    256K rw---   [ anon ]
5e7c0000     12K rw---   [ anon ]
5f580000    256K rw---   [ anon ]
71bfc000      4K -----   [ anon ]
71bfd000   8192K rw---   [ anon ]
723fd000      4K -----   [ anon ]
723fe000   8192K rw---   [ anon ]
72bfe000      4K -----   [ anon ]
72bff000   8192K rw---   [ anon ]
733ff000      4K -----   [ anon ]
73400000   8192K rw---   [ anon ]
73c00000    996K rw---   [ anon ]
73cf9000     28K -----   [ anon ]
73d80000   1536K rw---   [ anon ]
73f00000   1024K rw---   [ anon ]
74000000   1024K rw---   [ anon ]
74140000    256K rw---   [ anon ]
741db000    132K rw---   [ anon ]
741fc000      4K -----   [ anon ]
741fd000   8192K rw---   [ anon ]
749fd000      4K -----   [ anon ]
749fe000   8192K rw---   [ anon ]
751fe000      4K -----   [ anon ]
751ff000   8192K rw---   [ anon ]
759ff000      4K -----   [ anon ]
75a00000   8192K rw---   [ anon ]
76200000    132K rw---   [ anon ]
76221000    892K -----   [ anon ]
7634c000      4K -----   [ anon ]
7634d000     32K rw---   [ anon ]
76355000      4K -----   [ anon ]
76356000   8192K rw---   [ anon ]
76b56000   1276K r-x-- libc-2.31.so
76c95000     60K ----- libc-2.31.so
76ca4000      8K r---- libc-2.31.so
76ca6000      8K rw--- libc-2.31.so
76ca8000      8K rw---   [ anon ]
76caa000     96K r-x-- libpthread-2.31.so
76cc2000     64K ----- libpthread-2.31.so
76cd2000      4K r---- libpthread-2.31.so
76cd3000      4K rw--- libpthread-2.31.so
76cd4000      8K rw---   [ anon ]
76cd6000    112K r-x-- libgcc_s.so.1
76cf2000     60K ----- libgcc_s.so.1
76d01000      4K r---- libgcc_s.so.1
76d02000      4K rw--- libgcc_s.so.1
76d03000    376K r-x-- libm-2.31.so
76d61000     60K ----- libm-2.31.so
76d70000      4K r---- libm-2.31.so
76d71000      4K rw--- libm-2.31.so
76d72000   1468K r-x-- libstdc++.so.6.0.28
76ee1000     64K ----- libstdc++.so.6.0.28
76ef1000     20K r---- libstdc++.so.6.0.28
76ef6000      8K rw--- libstdc++.so.6.0.28
76ef8000      8K rw---   [ anon ]
76efa000     28K r-x-- libatomic.so.1.2.0
76f01000     60K ----- libatomic.so.1.2.0
76f10000      4K r---- libatomic.so.1.2.0
76f11000      4K rw--- libatomic.so.1.2.0
76f12000      4K rw---   [ anon ]
76f13000     12K r-x-- libdl-2.31.so
76f16000     60K ----- libdl-2.31.so
76f25000      4K r---- libdl-2.31.so
76f26000      4K rw--- libdl-2.31.so
76f27000     16K r-x-- libarmmem-v7l.so
76f2b000     60K ----- libarmmem-v7l.so
76f3a000      4K r---- libarmmem-v7l.so
76f3b000      4K rw--- libarmmem-v7l.so
76f3c000    136K r-x-- ld-2.31.so
76f60000     16K rw---   [ anon ]
76f6c000      8K rw---   [ anon ]
76f6e000      4K r---- ld-2.31.so
76f6f000      4K rw--- ld-2.31.so
7ef60000    132K rw---   [ stack ]
7ef98000      4K r-x--   [ anon ]
7ef99000      4K r----   [ anon ]
7ef9a000      4K r-x--   [ anon ]
ffff0000      4K r-x--   [ anon ]
 total   184700K

Here is the dump from the same time. Do you mind sharing how much this shows is in use (I'm currently reading up on how to analyze these files)?

lutron.1644775761986.heapsnapshot.txt

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

Chrome says that heap dump is 15625kB

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

I just added a line of code to 2.3.0-beta2 to emit a bit more information. lmk what it says pre- and post-memory growth.

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

Sorry I haven’t responded in a while. I got the idea to completely start over on my setup in case there was some other underlying issue. I wiped my pi and rebuilt my homebridge. I setup all my same plugins, but left Lutron off for a couple days. Everything was stable. I then added it back, and within hours started seeing the memory drain again.

I’ll be providing some more dumps soon. I’m totally confounded that no one else is having this issue though.

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

It is utterly mystifying. I’m really looking forward to seeing what the new log lines say. If they don’t report anything unusual, I’ll be stumped.

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

Dump near startup:

[Lutron] Current memory usage:
                          rss=71245824,
                          heapTotal=19398656, 
                          heapUsed=17442376,1
                          external=3479275, 
                          arrayBuffers=1309369,

Dump after memory drain

     Current memory usage:
                          rss=107536384,
                          heapTotal=22544384, 
                          heapUsed=15635536, 
                          external=3275737,
                          arrayBuffers=902986,

So this is interesting, but I feel there's something missing... about +/- 180 MB in memory lost attributed to the plugin's PID. What is the 'rss'?

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

RSS is "resident set size", which is the amount of memory that's "resident" and not ejected/swapped. That is to say, the amount of memory the process is actively in RAM. It's usually compared to VSZ.

I think this thread might be interesting to you. It appears that the nodejs runtime doesn't know anything about what's going on, as evidenced by the lack of growth in heap and external (which are where nodejs stores its objects and buffers, respectively). Both of those amounts (~23 MB and ~3 MB) are reasonable, and in line with my own amounts in my own RPi. Whatever is happening, it's happening inside nodejs.

(I will spare you my opinions of Javascript and Node. I am not a fan.)

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

So, this is still a mystery, particularly as the issue only occurs in conjunction with the plugin. But the thread you shared did help, and I seem to have memory more under control. Will continue to monitor, though now I’m dealing with timeouts like in #16.

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

Any new info?

from homebridge-lutron-caseta-leap.

rcoletti116 commented on July 19, 2024

It's been better, but I've struggled to keep the memory allocation changes stick between server restarts. I really want this to work well, especially since I've mounted a few Picos now. Given that I alone am having the issue and it seems related to Node rather than the plugin (though only happens with this plugin), I'll close this one out for you.

from homebridge-lutron-caseta-leap.

thenewwazoo commented on July 19, 2024

Thanks for working with me on it for so long. The fact that it only bites you is still really baffling and concerning but now we’ve got some diagnostic tools built at least

from homebridge-lutron-caseta-leap.

Memory Leak about homebridge-lutron-caseta-leap HOT 30 CLOSED

Comments (30)

Related Issues (20)

Recommend Projects

React

Vue.js

Typescript

TensorFlow

Django

Laravel

D3

Recommend Topics

javascript

web

server

Machine learning

Visualization

Game

Recommend Org

Facebook

Microsoft

Google

Alibaba

D3

Tencent