Skip to content
This repository has been archived by the owner on Apr 22, 2023. It is now read-only.

GC not works as expected with crypto module #5949

Closed
clowwindy opened this issue Jul 30, 2013 · 5 comments
Closed

GC not works as expected with crypto module #5949

clowwindy opened this issue Jul 30, 2013 · 5 comments

Comments

@clowwindy
Copy link 

node -e 'console.log(process.arch, process.platform, process.versions)'
x64 darwin { http_parser: '1.0',
  node: '0.10.15',
  v8: '3.14.5.9',
  ares: '1.9.0-DEV',
  uv: '0.10.13',
  zlib: '1.2.3',
  modules: '11',
  openssl: '1.0.1e' }

Here's a simple program that encrypts 16MB data 100 times:

var crypto = require('crypto');

var data = new Buffer(1024 * 1024 * 16);
for (var i = 0; i < 100; i++) {
    (function() {
        var cipher = crypto.createCipher('AES-256-CFB', 'my_password');
        cipher.update(data);
        cipher.final();
        cipher = null;
        console.log(i, process.memoryUsage());
    })();
}
data = null;

console.log('done!');

// wait and see if memory footprint reduces
setInterval(function() {
    console.log(process.memoryUsage());
}, 1000);

And we can see the gabage collector not work as expected. RSS went up to 300MB, after the encryption it never went down.

$ node --trace_gc lib/shadowsocks/memory.js
[51299]      465 ms: Mark-sweep 2.0 (36.0) -> 1.7 (38.0) MB, 3 / 8 ms [allocation failure] [GC in old space requested].
0 { rss: 64339968, heapTotal: 7195904, heapUsed: 1987336 }
1 { rss: 64729088, heapTotal: 7195904, heapUsed: 2365328 }
2 { rss: 81526784, heapTotal: 7195904, heapUsed: 2389152 }
3 { rss: 98312192, heapTotal: 7195904, heapUsed: 2397136 }
4 { rss: 115097600, heapTotal: 7195904, heapUsed: 2405120 }
5 { rss: 131883008, heapTotal: 7195904, heapUsed: 2413120 }
6 { rss: 148668416, heapTotal: 7195904, heapUsed: 2420976 }
7 { rss: 165453824, heapTotal: 7195904, heapUsed: 2428832 }
8 { rss: 182239232, heapTotal: 7195904, heapUsed: 2436632 }
9 { rss: 199020544, heapTotal: 7195904, heapUsed: 2444432 }
10 { rss: 215805952, heapTotal: 7195904, heapUsed: 2452232 }
11 { rss: 232591360, heapTotal: 7195904, heapUsed: 2460072 }
12 { rss: 249380864, heapTotal: 7195904, heapUsed: 2467912 }
13 { rss: 266166272, heapTotal: 7195904, heapUsed: 2475752 }
14 { rss: 283074560, heapTotal: 7195904, heapUsed: 2488088 }
15 { rss: 299859968, heapTotal: 7195904, heapUsed: 2495928 }
[51299]     6432 ms: Mark-sweep 2.4 (38.0) -> 2.2 (38.0) MB, 49 / 52 ms [external memory allocation limit reached] [GC in old space requested].
16 { rss: 316149760, heapTotal: 7195904, heapUsed: 2305304 }
17 { rss: 316149760, heapTotal: 7195904, heapUsed: 2321376 }
18 { rss: 316153856, heapTotal: 7195904, heapUsed: 2330800 }
19 { rss: 316153856, heapTotal: 7195904, heapUsed: 2338640 }
20 { rss: 316153856, heapTotal: 7195904, heapUsed: 2346440 }
21 { rss: 316153856, heapTotal: 7195904, heapUsed: 2354240 }
22 { rss: 316153856, heapTotal: 7195904, heapUsed: 2362040 }
23 { rss: 316153856, heapTotal: 7195904, heapUsed: 2369840 }
24 { rss: 316166144, heapTotal: 7195904, heapUsed: 2380616 }
25 { rss: 316166144, heapTotal: 7195904, heapUsed: 2388456 }
26 { rss: 316166144, heapTotal: 7195904, heapUsed: 2396256 }
27 { rss: 316178432, heapTotal: 7195904, heapUsed: 2406288 }
28 { rss: 316182528, heapTotal: 7195904, heapUsed: 2414464 }
29 { rss: 316252160, heapTotal: 7195904, heapUsed: 2435024 }
30 { rss: 316252160, heapTotal: 7195904, heapUsed: 2444240 }
31 { rss: 316264448, heapTotal: 7195904, heapUsed: 2462176 }
[51299]    12253 ms: Mark-sweep 2.4 (38.0) -> 2.2 (38.0) MB, 71 / 75 ms [external memory allocation limit reached] [GC in old space requested].
32 { rss: 316264448, heapTotal: 7195904, heapUsed: 2330696 }
33 { rss: 316268544, heapTotal: 7195904, heapUsed: 2349208 }
34 { rss: 316268544, heapTotal: 7195904, heapUsed: 2359784 }
35 { rss: 316268544, heapTotal: 7195904, heapUsed: 2371320 }
36 { rss: 316268544, heapTotal: 7195904, heapUsed: 2379120 }
37 { rss: 316268544, heapTotal: 7195904, heapUsed: 2386920 }
38 { rss: 316272640, heapTotal: 7195904, heapUsed: 2396248 }
39 { rss: 316272640, heapTotal: 7195904, heapUsed: 2404088 }
40 { rss: 316272640, heapTotal: 7195904, heapUsed: 2411888 }
41 { rss: 316272640, heapTotal: 7195904, heapUsed: 2422136 }
42 { rss: 316272640, heapTotal: 7195904, heapUsed: 2429936 }
43 { rss: 316272640, heapTotal: 7195904, heapUsed: 2437736 }
44 { rss: 316309504, heapTotal: 7195904, heapUsed: 2481952 }
45 { rss: 316309504, heapTotal: 7195904, heapUsed: 2491400 }
46 { rss: 316309504, heapTotal: 7195904, heapUsed: 2499200 }
47 { rss: 316309504, heapTotal: 7195904, heapUsed: 2507000 }
[51299]    18312 ms: Mark-sweep 2.4 (38.0) -> 2.3 (38.0) MB, 61 / 65 ms [external memory allocation limit reached] [GC in old space requested].
48 { rss: 316317696, heapTotal: 7195904, heapUsed: 2364000 }
49 { rss: 316317696, heapTotal: 7195904, heapUsed: 2379944 }
50 { rss: 316317696, heapTotal: 7195904, heapUsed: 2388840 }
51 { rss: 316317696, heapTotal: 7195904, heapUsed: 2396640 }
52 { rss: 316317696, heapTotal: 7195904, heapUsed: 2404440 }
53 { rss: 316317696, heapTotal: 7195904, heapUsed: 2412240 }
54 { rss: 316317696, heapTotal: 7195904, heapUsed: 2420040 }
55 { rss: 316317696, heapTotal: 7195904, heapUsed: 2427840 }
56 { rss: 316317696, heapTotal: 7195904, heapUsed: 2435640 }
57 { rss: 316317696, heapTotal: 7195904, heapUsed: 2443440 }
58 { rss: 316317696, heapTotal: 7195904, heapUsed: 2451240 }
59 { rss: 316321792, heapTotal: 7195904, heapUsed: 2459040 }
60 { rss: 316321792, heapTotal: 7195904, heapUsed: 2466880 }
61 { rss: 316321792, heapTotal: 7195904, heapUsed: 2476416 }
62 { rss: 316321792, heapTotal: 7195904, heapUsed: 2484216 }
63 { rss: 316321792, heapTotal: 7195904, heapUsed: 2492016 }
[51299]    24390 ms: Mark-sweep 2.4 (38.0) -> 2.2 (38.0) MB, 64 / 68 ms [external memory allocation limit reached] [GC in old space requested].
64 { rss: 316321792, heapTotal: 7195904, heapUsed: 2340344 }
65 { rss: 316321792, heapTotal: 7195904, heapUsed: 2356288 }
66 { rss: 316346368, heapTotal: 7195904, heapUsed: 2376680 }
67 { rss: 316346368, heapTotal: 7195904, heapUsed: 2384856 }
68 { rss: 316346368, heapTotal: 7195904, heapUsed: 2392656 }
69 { rss: 316346368, heapTotal: 7195904, heapUsed: 2400456 }
70 { rss: 316346368, heapTotal: 7195904, heapUsed: 2408256 }
71 { rss: 316350464, heapTotal: 7195904, heapUsed: 2416056 }
72 { rss: 316350464, heapTotal: 7195904, heapUsed: 2423896 }
73 { rss: 316350464, heapTotal: 7195904, heapUsed: 2431696 }
74 { rss: 316350464, heapTotal: 7195904, heapUsed: 2439496 }
75 { rss: 316489728, heapTotal: 7195904, heapUsed: 2465560 }
76 { rss: 316489728, heapTotal: 7195904, heapUsed: 2473400 }
77 { rss: 316489728, heapTotal: 7195904, heapUsed: 2481200 }
78 { rss: 316489728, heapTotal: 7195904, heapUsed: 2491000 }
79 { rss: 317038592, heapTotal: 7195904, heapUsed: 2540600 }
[51299]    30422 ms: Mark-sweep 2.4 (38.0) -> 2.2 (38.0) MB, 57 / 60 ms [external memory allocation limit reached] [GC in old space requested].
80 { rss: 316416000, heapTotal: 7195904, heapUsed: 2261336 }
81 { rss: 316424192, heapTotal: 7195904, heapUsed: 2290056 }
82 { rss: 316428288, heapTotal: 7195904, heapUsed: 2306256 }
83 { rss: 316428288, heapTotal: 7195904, heapUsed: 2315232 }
84 { rss: 316428288, heapTotal: 7195904, heapUsed: 2323032 }
85 { rss: 316428288, heapTotal: 7195904, heapUsed: 2330832 }
86 { rss: 316428288, heapTotal: 7195904, heapUsed: 2338632 }
87 { rss: 316428288, heapTotal: 7195904, heapUsed: 2346432 }
88 { rss: 316428288, heapTotal: 7195904, heapUsed: 2354232 }
89 { rss: 316428288, heapTotal: 7195904, heapUsed: 2362032 }
90 { rss: 316428288, heapTotal: 7195904, heapUsed: 2369832 }
91 { rss: 316428288, heapTotal: 7195904, heapUsed: 2377632 }
92 { rss: 316428288, heapTotal: 7195904, heapUsed: 2390824 }
93 { rss: 316432384, heapTotal: 7195904, heapUsed: 2398920 }
94 { rss: 316432384, heapTotal: 7195904, heapUsed: 2406760 }
95 { rss: 316432384, heapTotal: 7195904, heapUsed: 2414560 }
[51299]    36286 ms: Mark-sweep 2.3 (38.0) -> 2.1 (38.0) MB, 67 / 69 ms [external memory allocation limit reached] [GC in old space requested].
96 { rss: 316436480, heapTotal: 7195904, heapUsed: 2173216 }
97 { rss: 316448768, heapTotal: 7195904, heapUsed: 2241344 }
98 { rss: 316448768, heapTotal: 7195904, heapUsed: 2261272 }
99 { rss: 316448768, heapTotal: 7195904, heapUsed: 2271000 }
done!
{ rss: 316522496, heapTotal: 7195904, heapUsed: 2359208 }
{ rss: 316526592, heapTotal: 7195904, heapUsed: 2372640 }
{ rss: 316526592, heapTotal: 7195904, heapUsed: 2380464 }
{ rss: 316526592, heapTotal: 7195904, heapUsed: 2387568 }
{ rss: 316526592, heapTotal: 7195904, heapUsed: 2394672 }
{ rss: 316526592, heapTotal: 7195904, heapUsed: 2401808 }
{ rss: 316526592, heapTotal: 7195904, heapUsed: 2408912 }
{ rss: 316526592, heapTotal: 7195904, heapUsed: 2416016 }
{ rss: 316526592, heapTotal: 7195904, heapUsed: 2423120 }
{ rss: 316526592, heapTotal: 7195904, heapUsed: 2430224 }
{ rss: 316526592, heapTotal: 7195904, heapUsed: 2437360 }

I also found that a simple loop of crypto.randomBytes(16 * 1024 * 1024) will lead to the same result.

With --expose-gc supplied, doing gc() manually after each iteration, RSS only takes up to 65MB.
@clowwindy clowwindy mentioned this issue Jul 30, 2013
Open
@bnoordhuis
Copy link
Member

That's not unexpected. It's an artifact of how buffers and the garbage collector interact.

The V8 GC takes a lazy approach to memory management, it tries to do as little work as possible because garbage collection is expensive.

The flip side of that is that buffers - which are essentially tiny JS objects that point to memory outside of the JS heap - tend to live longer and hold on to that external memory longer than is strictly needed.

It has been addressed to some extent in master but the basic issue will never go away completely. If that's a problem for you, you'll have to invoke the garbage collector manually from time to time.

@meteormatt
Copy link

@bnoordhuis 👍

@Bernou
Copy link

Bernou commented Jan 24, 2016

greate

@zqw
Copy link

zqw commented Jun 29, 2016

great!

@ReadmeCritic ReadmeCritic mentioned this issue Aug 10, 2016
Merged
@supermoonie
Copy link

great!

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@bnoordhuis @meteormatt @clowwindy @zqw @Bernou @supermoonie