storj-archived/storjshare-daemon

Memory Leak - Daemon Crash Log

Closed this issue · 14 comments

Package Versions

Replace the values below using the output from storjshare --version.

daemon: 4.0.1, core: 7.0.2, protocol: 1.2.0

Replace the values below using the output from node --version.

v6.11.3

Expected Behavior

Please describe the program's expected behavior.

Actual Behavior

Please describe the program's actual behavior. Please include any stack traces
or log output in the back ticks below.

<--- Last few GCs --->

   47184 ms: Mark-sweep 1378.5 (1436.7) -> 1378.5 (1436.7) MB, 995.5 / 7.9 ms [allocation failure] [GC in old space requested].
   48180 ms: Mark-sweep 1378.5 (1436.7) -> 1378.5 (1436.7) MB, 995.9 / 7.9 ms [allocation failure] [GC in old space requested].
   49268 ms: Mark-sweep 1378.5 (1436.7) -> 1379.6 (1417.7) MB, 1087.9 / 7.9 ms [last resort gc].
   50349 ms: Mark-sweep 1379.6 (1417.7) -> 1380.8 (1417.7) MB, 1080.2 / 7.9 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x1a982cccf781 <JS Object>
    2: normalize [path.js:~1183] [pc=0x6ec729e9a72] (this=0x107602aa49b9 <an Object with map 0x24fb564135b9>,path=0x14d34f9dec49 <String[50]: /root/Storj/Storj01/sharddata.kfs/225.s/145705.ldb>)
    3: join [path.js:~1212] [pc=0x6ec729e600e] (this=0x107602aa49b9 <an Object with map 0x24fb564135b9>)
    4: arguments adaptor frame: 2->0
    5: /* anonymous */ [/usr/lib/node_modules/storjshare-dae...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [node]
 2: 0x109f0ac [node]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [node]
 5: v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) [node]
 6: v8::internal::Runtime_AllocateInTargetSpace(int, v8::internal::Object**, v8::internal::Isolate*) [node]
 7: 0x6ec725079a7
<--- Last few GCs --->

   47363 ms: Mark-sweep 1379.7 (1436.7) -> 1379.6 (1436.7) MB, 949.5 / 7.9 ms [allocation failure] [GC in old space requested].
   48314 ms: Mark-sweep 1379.6 (1436.7) -> 1379.7 (1436.7) MB, 950.5 / 7.9 ms [allocation failure] [GC in old space requested].
   49353 ms: Mark-sweep 1379.7 (1436.7) -> 1380.8 (1420.7) MB, 1039.1 / 8.0 ms [last resort gc].
   50383 ms: Mark-sweep 1380.8 (1420.7) -> 1381.9 (1420.7) MB, 1029.7 / 7.9 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x3bf5772cf781 <JS Object>
    1: InnerArrayForEach(aka InnerArrayForEach) [native array.js:~935] [pc=0x25b2faadd966] (this=0x3bf577204381 <undefined>,bq=0x3272f9b8189 <JS Function (SharedFunctionInfo 0x3fe14e197cd1)>,br=0x3bf577204381 <undefined>,w=0x231bada52301 <JS Array[7772]>,x=7772)
    2: forEach [native array.js:~954] [pc=0x25b2fa642acd] (this=0x231bada52301 <JS Array[7772]>,bq=0x3272f9b8189 <JS Function (SharedF...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [node]
 2: 0x109f0ac [node]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [node]
 5: v8::internal::Factory::NewRawOneByteString(int, v8::internal::PretenureFlag) [node]
 6: v8::internal::Factory::NewStringFromOneByte(v8::internal::Vector<unsigned char const>, v8::internal::PretenureFlag) [node]
 7: v8::internal::Factory::NumberToString(v8::internal::Handle<v8::internal::Object>, bool) [node]
 8: v8::internal::Object::ToString(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
 9: v8::internal::Object::ConvertToName(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
10: v8::internal::Runtime_HasProperty(int, v8::internal::Object**, v8::internal::Isolate*) [node]
11: 0x25b2fa6092a7
<--- Last few GCs --->

   52831 ms: Mark-sweep 1381.7 (1437.7) -> 1381.7 (1437.7) MB, 984.7 / 8.3 ms [allocation failure] [GC in old space requested].
   53909 ms: Mark-sweep 1381.7 (1437.7) -> 1382.8 (1419.7) MB, 1078.1 / 8.4 ms [last resort gc].
   54987 ms: Mark-sweep 1382.8 (1419.7) -> 1384.0 (1419.7) MB, 1078.2 / 8.4 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x21732f6cf781 <JS Object>
    1: map [native array.js:~994] [pc=0xeeab83eb998] (this=0x2a75576fe761 <JS Array[7525]>,bq=0xe4cb9f30359 <JS Function (SharedFunctionInfo 0x367750699359)>,br=0x21732f604381 <undefined>)
    2: arguments adaptor frame: 1->2
    3: /* anonymous */ [/usr/lib/node_modules/storjshare-daemon/node_modules/du/index.js:27] [pc=0xeeab83e3f00] (this=0x1a9bee3a6ff9 <JS Global Object>,err=0x21732f604201 ...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [node]
 2: 0x109f0ac [node]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [node]
 5: v8::internal::Factory::NewRawOneByteString(int, v8::internal::PretenureFlag) [node]
 6: v8::internal::Factory::NewStringFromOneByte(v8::internal::Vector<unsigned char const>, v8::internal::PretenureFlag) [node]
 7: v8::internal::Factory::NumberToString(v8::internal::Handle<v8::internal::Object>, bool) [node]
 8: v8::internal::Object::ToString(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
 9: v8::internal::Object::ConvertToName(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
10: v8::internal::Runtime_HasProperty(int, v8::internal::Object**, v8::internal::Isolate*) [node]
11: 0xeeab7f092a7

Steps to Reproduce

Please include the steps the reproduce the issue, numbered below. Include as
much detail as possible.

  1. Start Daemon in foreground
  2. Start Config
  3. Daemon Crash with above error

This is still happening:

storjshare --version
daemon: 4.0.1, core: 7.0.3, protocol: 1.2.0
<--- Last few GCs --->

   47981 ms: Mark-sweep 1383.6 (1437.7) -> 1383.6 (1437.7) MB, 995.5 / 8.4 ms [allocation failure] [GC in old space requested].
   48978 ms: Mark-sweep 1383.6 (1437.7) -> 1383.6 (1437.7) MB, 997.3 / 8.4 ms [allocation failure] [GC in old space requested].
   50061 ms: Mark-sweep 1383.6 (1437.7) -> 1384.8 (1421.7) MB, 1082.5 / 8.4 ms [last resort gc].
   51133 ms: Mark-sweep 1384.8 (1421.7) -> 1386.0 (1421.7) MB, 1072.3 / 8.4 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x2467849cf781 <JS Object>
    1: map [native array.js:~994] [pc=0x223381fe2398] (this=0x386a256be8a9 <JS Array[7836]>,bq=0x1b6fba24401 <JS Function (SharedFunctionInfo 0x1351298a3101)>,br=0x246784904381 <undefined>)
    2: arguments adaptor frame: 1->2
    3: /* anonymous */ [/usr/lib/node_modules/storjshare-daemon/node_modules/du/index.js:27] [pc=0x223381fda600] (this=0x339f808a85e9 <JS Global Object>,err=0x24678490420...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [node]
 2: 0x109f0ac [node]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [node]
 5: v8::internal::Factory::NewRawOneByteString(int, v8::internal::PretenureFlag) [node]
 6: v8::internal::Factory::NewStringFromOneByte(v8::internal::Vector<unsigned char const>, v8::internal::PretenureFlag) [node]
 7: v8::internal::Factory::NumberToString(v8::internal::Handle<v8::internal::Object>, bool) [node]
 8: v8::internal::Object::ToString(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
 9: v8::internal::Object::ConvertToName(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
10: v8::internal::Runtime_HasProperty(int, v8::internal::Object**, v8::internal::Isolate*) [node]
11: 0x223381b092a7
<--- Last few GCs --->

   40719 ms: Mark-sweep 1381.4 (1435.7) -> 1381.4 (1435.7) MB, 1019.2 / 8.4 ms [allocation failure] [GC in old space requested].
   41738 ms: Mark-sweep 1381.4 (1435.7) -> 1381.4 (1435.7) MB, 1018.6 / 8.4 ms [allocation failure] [GC in old space requested].
   42885 ms: Mark-sweep 1381.4 (1435.7) -> 1382.5 (1419.7) MB, 1146.7 / 8.4 ms [last resort gc].
   44023 ms: Mark-sweep 1382.5 (1419.7) -> 1383.6 (1419.7) MB, 1138.4 / 8.4 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x1c026c3cf781 <JS Object>
    1: InnerArrayForEach(aka InnerArrayForEach) [native array.js:~935] [pc=0xc0b497e5e46] (this=0x1c026c304381 <undefined>,bq=0x523fdca7c79 <JS Function (SharedFunctionInfo 0x15f735e8f331)>,br=0x1c026c304381 <undefined>,w=0x134555f3cf31 <JS Array[7968]>,x=7968)
    2: forEach [native array.js:~954] [pc=0xc0b49342f2d] (this=0x134555f3cf31 <JS Array[7968]>,bq=0x523fdca7c79 <JS Function (SharedFun...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [node]
 2: 0x109f0ac [node]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [node]
 5: v8::internal::Factory::NewRawOneByteString(int, v8::internal::PretenureFlag) [node]
 6: v8::internal::Factory::NewStringFromOneByte(v8::internal::Vector<unsigned char const>, v8::internal::PretenureFlag) [node]
 7: v8::internal::Factory::NumberToString(v8::internal::Handle<v8::internal::Object>, bool) [node]
 8: v8::internal::Object::ToString(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
 9: v8::internal::Object::ConvertToName(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
10: v8::internal::Runtime_HasProperty(int, v8::internal::Object**, v8::internal::Isolate*) [node]
11: 0xc0b493092a7
free -mh
              total        used        free      shared  buff/cache   available
Mem:            62G        230M         55G         64M        7.1G         61G
uname -a
Linux host 4.10.0-33-generic #37~16.04.1-Ubuntu SMP Fri Aug 11 14:07:24 UTC 2017 x86_64 x86_64 x86_64 GNU/Linux

I bet the used space query is the problem. The old daemon version was using KFS to get the used space. That was very fast but doesn't include the file system overhead.

The new daemon is using node-du to query the used space.

I will need a few hours / days to prepare a test. I will run the used space query every 30 minutes and create some memory snapshots.

Worksaround for now:
npm install -g storjshare-daemon@v3.5.5

@littleskunk @aleitner

storjshare -V
daemon: 3.5.5, core: 6.8.0, protocol: 1.1.0
nodejs -v
v6.11.3

Node 1

{"level":"info","message":"attempting to start share with config at path /root/.config/storjshare/configs/d42c2602255c159010ac60b5e151c0845fe1adb6.json","timestamp":"2017-09-12T15:49:40.894Z"}

<--- Last few GCs --->

   53430 ms: Mark-sweep 1378.0 (1435.7) -> 1378.0 (1435.7) MB, 1078.5 / 13.1 ms [allocation failure] [GC in old space requested].
   54630 ms: Mark-sweep 1378.0 (1435.7) -> 1379.1 (1413.7) MB, 1199.5 / 13.1 ms [last resort gc].
   55818 ms: Mark-sweep 1379.1 (1413.7) -> 1380.3 (1413.7) MB, 1188.5 / 13.1 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x1642a0ecf781 <JS Object>
    1: InnerArrayForEach(aka InnerArrayForEach) [native array.js:~935] [pc=0x37201beddee6] (this=0x1642a0e04381 <undefined>,bq=0x1c81ad6bc79 <JS Function (SharedFunctionInfo 0xc953244d319)>,br=0x1642a0e04381 <undefined>,w=0x523f2f04e91 <JS Array[7832]>,x=7832)
    2: forEach [native array.js:~954] [pc=0x37201ba42f2d] (this=0x523f2f04e91 <JS Array[7832]>,bq=0x1c81ad6bc79 <JS Function (SharedFunc...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [node]
 2: 0x109f0ac [node]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [node]
 5: v8::internal::Factory::NewRawOneByteString(int, v8::internal::PretenureFlag) [node]
 6: v8::internal::Factory::NewStringFromOneByte(v8::internal::Vector<unsigned char const>, v8::internal::PretenureFlag) [node]
 7: v8::internal::Factory::NumberToString(v8::internal::Handle<v8::internal::Object>, bool) [node]
 8: v8::internal::Object::ToString(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
 9: v8::internal::Object::ConvertToName(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
10: v8::internal::Runtime_HasProperty(int, v8::internal::Object**, v8::internal::Isolate*) [node]
11: 0x37201ba092a7

Node 2

{"level":"info","message":"attempting to start share with config at path /root/.config/storjshare/configs/80e92fb302f0cca13ec09086e14983b3135cb603.json","timestamp":"2017-09-12T15:50:59.552Z"}

<--- Last few GCs --->

   40081 ms: Mark-sweep 1377.8 (1435.7) -> 1377.8 (1435.7) MB, 1092.2 / 12.5 ms [allocation failure] [GC in old space requested].
   41291 ms: Mark-sweep 1377.8 (1435.7) -> 1378.9 (1418.7) MB, 1209.5 / 12.5 ms [last resort gc].
   42489 ms: Mark-sweep 1378.9 (1418.7) -> 1380.1 (1418.7) MB, 1198.2 / 12.5 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x3d361a2cf781 <JS Object>
    2: normalize [path.js:~1183] [pc=0xdf8e38ef392] (this=0x2d61d90a7591 <an Object with map 0x1b8eb27135b9>,path=0x2fd9c23eaac9 <String[50]: /root/Storj/Storj02/sharddata.kfs/227.s/121100.ldb>)
    3: join [path.js:~1212] [pc=0xdf8e38eccee] (this=0x2d61d90a7591 <an Object with map 0x1b8eb27135b9>)
    4: arguments adaptor frame: 2->0
    5: /* anonymous */ [/usr/lib/node_modules/storjshare-dae...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [node]
 2: 0x109f0ac [node]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [node]
 5: v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationSpace) [node]
 6: v8::internal::Runtime_AllocateInTargetSpace(int, v8::internal::Object**, v8::internal::Isolate*) [node]
 7: 0xdf8e34079a7
storjshare -V
daemon: 4.0.2-beta.1, core: 7.0.3, protocol: 1.2.0
<--- Last few GCs --->

   44865 ms: Mark-sweep 1381.2 (1434.7) -> 1381.1 (1434.7) MB, 1048.0 / 13.3 ms [allocation failure] [GC in old space requested].
   45914 ms: Mark-sweep 1381.1 (1434.7) -> 1381.1 (1434.7) MB, 1048.0 / 13.2 ms [allocation failure] [GC in old space requested].
   47076 ms: Mark-sweep 1381.1 (1434.7) -> 1382.3 (1418.7) MB, 1162.2 / 13.2 ms [last resort gc].
   48231 ms: Mark-sweep 1382.3 (1418.7) -> 1383.6 (1418.7) MB, 1155.1 / 13.2 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x39beecbcf781 <JS Object>
    1: InnerArrayForEach(aka InnerArrayForEach) [native array.js:~935] [pc=0x198340bda8c6] (this=0x39beecb04381 <undefined>,bq=0x226cfb83cbf1 <JS Function (SharedFunctionInfo 0x23cd1fe8bad9)>,br=0x39beecb04381 <undefined>,w=0x226cfb8bbb21 <JS Array[9412]>,x=9412)
    2: forEach [native array.js:~954] [pc=0x198340742f2d] (this=0x226cfb8bbb21 <JS Array[9412]>,bq=0x226cfb83cbf1 <JS Function (Share...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [node]
 2: 0x109f0ac [node]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [node]
 5: v8::internal::Factory::NewRawOneByteString(int, v8::internal::PretenureFlag) [node]
 6: v8::internal::Factory::NewStringFromOneByte(v8::internal::Vector<unsigned char const>, v8::internal::PretenureFlag) [node]
 7: v8::internal::Factory::NumberToString(v8::internal::Handle<v8::internal::Object>, bool) [node]
 8: v8::internal::Object::ToString(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
 9: v8::internal::Object::ConvertToName(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
10: v8::internal::Runtime_HasProperty(int, v8::internal::Object**, v8::internal::Isolate*) [node]
11: 0x1983407092a7
<--- Last few GCs --->

   46463 ms: Mark-sweep 1383.8 (1438.7) -> 1383.7 (1438.7) MB, 1046.9 / 13.2 ms [allocation failure] [GC in old space requested].
   47510 ms: Mark-sweep 1383.7 (1438.7) -> 1383.8 (1438.7) MB, 1046.9 / 13.4 ms [allocation failure] [GC in old space requested].
   48672 ms: Mark-sweep 1383.8 (1438.7) -> 1384.9 (1422.7) MB, 1161.7 / 13.3 ms [last resort gc].
   49838 ms: Mark-sweep 1384.9 (1422.7) -> 1386.1 (1422.7) MB, 1166.3 / 13.3 ms [last resort gc].


<--- JS stacktrace --->

==== JS stack trace =========================================

Security context: 0x254e33bcf781 <JS Object>
    1: map [native array.js:~994] [pc=0x28daaccd89f8] (this=0x2aedef8f7209 <JS Array[7832]>,bq=0x323a12912199 <JS Function (SharedFunctionInfo 0x29a32fb8a0f1)>,br=0x254e33b04381 <undefined>)
    2: arguments adaptor frame: 1->2
    3: /* anonymous */ [/usr/lib/node_modules/storjshare-daemon/node_modules/du/index.js:27] [pc=0x28daacccecc0] (this=0x15bc5b3a71a9 <JS Global Object>,err=0x254e33b042...

FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory
 1: node::Abort() [node]
 2: 0x109f0ac [node]
 3: v8::Utils::ReportApiFailure(char const*, char const*) [node]
 4: v8::internal::V8::FatalProcessOutOfMemory(char const*, bool) [node]
 5: v8::internal::Factory::NewRawOneByteString(int, v8::internal::PretenureFlag) [node]
 6: v8::internal::Factory::NewStringFromOneByte(v8::internal::Vector<unsigned char const>, v8::internal::PretenureFlag) [node]
 7: v8::internal::Factory::NumberToString(v8::internal::Handle<v8::internal::Object>, bool) [node]
 8: v8::internal::Object::ToString(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
 9: v8::internal::Object::ConvertToName(v8::internal::Isolate*, v8::internal::Handle<v8::internal::Object>) [node]
10: v8::internal::Runtime_HasProperty(int, v8::internal::Object**, v8::internal::Isolate*) [node]
11: 0x28daac8092a7

It looks like the new "diskusage" package is running into out of memory exceptions.

@braydonf @aleitner As hotfix we should switch back to fd-diskspace.

Wasn't this happening at daemon v4.0.1 and even earlier versions also?

Do you mean #114 ? No that issue is different. The old daemon was hitting the out of memory exception after a few hours or days.

The new daemon will do it on the first call.

I still try to verify this myself but moving the shards takes more time than expected.

@braydonf It wasn't happening in v3.5.5. However, once I upgraded to v.4.0.1 and rolled back to v3.5.5 it started to happen at the start.

@braydonf Now I am sure. I did some tests with a 800GB farmer. The old implementation needs 500MB memory for a short time. The new implementation needs 2 times 400-500MB. 800MB - 1GB total.

I see 2 problems here.
1.) The used space calculation is executed 2 times on startup. Double checking the used space is killing the farmer. We should remove one.
https://github.com/Storj/storjshare-daemon/blob/96d46a98f9a9c764a42aac67d2227d690e53bb22/lib/utils.js#L114
https://github.com/Storj/core/blob/19f5a5dd120f03f75da89a518e7cb468e6a4c166/lib/network/farmer.js#L328
2.) Even if the farmer would need only one time 400MB-500MB it is still too many. A full 8TB farmer would need 4GB-5GB memory for checking used space every 24hours. Any ideas how we fix that?

Okay, I think we can skip the usage checks that iterate over directories and files for the time being actually.

@braydonf any ETA on fix have 8 TB offline due to this bug.

The issue is still not revolved in daemon version 5.

Closing as reported as resolved with #254