Re: [nodejs] Is growing RSS something to worry about.

[Fedor Indutny]

Hi,

std::bad_alloc isn't happening anymore because it was addressed in this commit: https://github.com/joyent/node/commit/4165f736e65215bc39b38186582022039068c108

RSS size depends on what you're actually doing, TLS server may eat much more memory than HTTP one, and just TCP server may eat even less.

Cheers,

Fedor.

On Thu, Oct 11, 2012 at 6:34 PM, Jaan Oras <jaan...@gmail.com> wrote:

Hi

I'm a bit puzzled by the growing RSS size of node process, and while this has been discussed here a few times I've not seen a good explanation for this.

The problem: while running load tests against our software the v8 heap stays relatively stable, but RSS usage of the process grows quite high compared to the heap, I've seen about 700MB for 32bit node ja 1G for 64bit node. Sometimes the RSS growth stabilises(does not grow after running load tests) at different points, but after a while it grows again, but I havent seen it decline.  

Also, while inspecting the objects in the JS heap, there are only about 10 Buffer objects and none of them are big, so it does not seem to be a Buffer leak. At the same time mdb-s ::findjsobjects finds thousands of Buffer objects with many wiht size about 40kB, that are not referenced from anywhere, but I dont know enough about v8 and about the mdb v8 module to deduct anything from that. Maybe it is somekind of internal buffer pool or just already freed objects.

mdb log is available here http://dl.dropbox.com/u/26529751/debug.out, RSS/heap/heap used was 193986560/28994560/14488064 bytes at the time.

The reason why I'm interested in the RSS growth is that we have seen a crash with std::bad_alloc with node 0.8.9 32bit at about 500MB level, though I havent been able to reproduce it with 0.8.11.

So the question is, is this something I should worry about, or is this growth an expected behaviour, and it will stop at some limit or is something wrong?

To illustrate the issue I've ran some tests and plotted the process.memoryUsage():

Sysinfo

-------------

  "Live Image": "20121004T212912Z",

  "System Type": "SunOS",

  "Manufacturer": "Dell Inc.",

  "Product": "PowerEdge R710",

  "VM Capable": true,

  "CPU Type": "Intel(R) Xeon(R) CPU E5606 @ 2.13GHz",

  "CPU Virtualization": "vmx",

  "CPU Physical Cores": 1,

  "CPU Total Cores": 4,

  "MiB of Memory": "12276",

32bit node

--------------

Graph of process.memoryUsage(): 

https://docs.google.com/spreadsheet/oimg?key=0Ah6DEw0ncda2dFdDem5fVmI5eU5sRlJvRjJ4eTdVS1E&oid=4&zx=t856kh9n0cqq

Message from gc at the end of the test:

1370378 ms: Mark-sweep 11.6 (30.6) -> 10.2 (29.6) MB, 1 / 26 ms [allocation failure] [GC in old space requested].

Memory allocator,   used: 31059968, available: 736497664

New space,          used:    14808, available:  8373800

Old pointers,       used:  3309184, available:        0, waste:        0

Old data space,     used:  5007776, available:   267232, waste:        0

Code space,         used:  3158080, available:   245696, waste:        0

Map space,          used:   223488, available:   923264, waste:        0

Cell space,         used:    85176, available:    13128, waste:        0

Large object space, used:        0, available: 735416192

64bit node

--------------

Graph of process.memoryUsage(): 

https://docs.google.com/spreadsheet/oimg?key=0Ah6DEw0ncda2dFdDem5fVmI5eU5sRlJvRjJ4eTdVS1E&oid=2&zx=1wfwmy7gbjzt

Message from gc at the end of the test:

948639 ms: Mark-sweep 27.2 (54.0) -> 15.5 (54.0) MB, 4 / 30 ms [external memory allocation limit reached] [GC in old space requested].

Memory allocator,   used: 56606720, available: 1478508544

New space,          used:    98304, available: 16678912

Old pointers,       used:  6661664, available:  1086176, waste:        0

Old data space,     used:  4586488, available:   769800, waste:        0

Code space,         used:  4368896, available:   730624, waste:        0

Map space,          used:   430280, available:   732728, waste:        0

Cell space,         used:   172336, available:   957904, waste:        0

Large object space, used:        0, available: 1477443328

--
Job Board: http://jobs.nodejs.org/
Posting guidelines: https://github.com/joyent/node/wiki/Mailing-List-Posting-Guidelines
You received this message because you are subscribed to the Google
Groups "nodejs" group.
To post to this group, send email to nod...@googlegroups.com
To unsubscribe from this group, send email to
nodejs+un...@googlegroups.com
For more options, visit this group at
http://groups.google.com/group/nodejs?hl=en?hl=en

[Ben Noordhuis]

That std::bad_alloc you got may have been caused (or rather: fixed) by
[1] which is pending a back-port to v0.8.

Regarding buffers, until last night[2] their sizes were not reported
properly in heap snapshots. That may not apply to mdb though, I don't
know if it uses the heap profiler API.

[1] https://github.com/joyent/node/commit/7bd84de
[2] https://github.com/joyent/node/commit/6a128e0

[Ben Noordhuis]

On Thu, Oct 11, 2012 at 1:59 PM, Ben Noordhuis <in...@bnoordhuis.nl> wrote:
> That std::bad_alloc you got may have been caused (or rather: fixed) by
> [1] which is pending a back-port to v0.8.

Belay that, Isaac back-ported it in v0.8.10. That's probably why it
was failing in 0.8.9 and working with 0.8.11.

[Nico Kaiser]

Hi!

Maybe this is related:

https://github.com/einaros/ws/issues/43

Some users experience high RSS usage which does not shrink. Maybe node fails to properly free RSS memory used by buffers, so the process will use all memory it can get over the time (some days), though it does not crash but have a rather constant memory consumption.

Nico

[Jaan Oras]

Hi

I've tried to 0.8.9 and I get consistent crashes, with 0.8.11 I dont get crashes, so I guess the crashing part is fixed. The RSS still grows but finally stops at some point(about 700MB for 32bit process), but it is still weird that sometimes after the same loadtest RSS is 700MB sometimes 250MB.

I guess it is not problem for me at the moment, but I figure that this kind of behaviour is quite limiting for people using cluster module.

0.8.12 claims to display proper retained size of buffer, I'll see what it shows.

Jaan Oras