Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Memory Leak Issue Tracker #111

Open
prastut opened this issue May 16, 2020 · 5 comments
Open

Memory Leak Issue Tracker #111

prastut opened this issue May 16, 2020 · 5 comments
Labels
-size-l +P2 Priority 2 - Medium priority robustness-problem
Milestone
Core Tech Optimiz...

Comments

@prastut
Copy link
Member

prastut commented May 16, 2020 •
edited
Loading

DB related errors:

May 16 09:43:47 PM  MongoError: Cache Reader No keys found for HMAC that is valid for time: { ts: Timestamp(1589645567, 1) } with id: 6771397799096352771
    at Connection.<anonymous> (/opt/render/project/src/node_modules/mongodb/lib/core/connection/pool.js:460:61)
    at Connection.emit (events.js:310:20)
    at Connection.EventEmitter.emit (domain.js:482:12)
    at processMessage (/opt/render/project/src/node_modules/mongodb/lib/core/connection/connection.js:368:10)
    at TLSSocket.<anonymous> (/opt/render/project/src/node_modules/mongodb/lib/core/connection/connection.js:537:15)
    at TLSSocket.emit (events.js:310:20)
    at TLSSocket.EventEmitter.emit (domain.js:482:12)
    at addChunk (_stream_readable.js:286:12)
    at readableAddChunk (_stream_readable.js:268:9)
    at TLSSocket.Readable.push (_stream_readable.js:209:10)
    at TLSWrap.onStreamRead (internal/stream_base_commons.js:186:23) {
May 16 09:43:47 PM    ok: 0,
May 16 09:43:47 PM    errmsg: 'Cache Reader No keys found for HMAC that is valid for time: { ts: Timestamp(1589645567, 1) } with id: 6771397799096352771',
May 16 09:43:47 PM    code: 211,
May 16 09:43:47 PM    codeName: 'KeyNotFound',
May 16 09:43:47 PM    name: 'MongoError',
May 16 09:43:47 PM    [Symbol(mongoErrorContextSymbol)]: {}
May 16 09:43:47 PM  }

Memory leaks

May 16 09:28:22 PM  eraProgress 2703
May 16 09:28:22 PM  eraProgress 2704
May 16 09:28:43 PM  
May 16 09:28:43 PM  <--- Last few GCs --->
May 16 09:28:43 PM  
May 16 09:28:43 PM  [35:0x392c790] 15307074 ms: Mark-sweep 252.2 (257.7) -> 251.5 (257.7) MB, 1198.9 / 0.0 ms  (average mu = 0.092, current mu = 0.003) allocation failure scavenge might not succeed
May 16 09:28:43 PM  [35:0x392c790] 15308381 ms: Mark-sweep 252.4 (257.7) -> 251.7 (257.7) MB, 1295.7 / 0.0 ms  (average mu = 0.050, current mu = 0.008) allocation failure scavenge might not succeed
May 16 09:28:43 PM  
May 16 09:28:43 PM  
May 16 09:28:43 PM  <--- JS stacktrace --->
May 16 09:28:43 PM  
May 16 09:28:43 PM  ==== JS stack trace =========================================
May 16 09:28:43 PM  
May 16 09:28:43 PM      0: ExitFrame [pc: 0x13c03d9]
May 16 09:28:43 PM  Security context: 0x0952793408d1 <JSObject>
May 16 09:28:43 PM      1: /* anonymous */ [0x18b7eab3b841] [/opt/render/project/src/node_modules/mongoose/lib/schema.js:~611] [pc=0x271ea63fc279](this=0x3cc850164e91 <Schema map = 0x145a1b3312b9>,0x1c5d98e1a0c1 <String[#3]: _id>,0x1d077fa804b1 <undefined>)
May 16 09:28:43 PM      2: /* anonymous */ [0x3c1b46453a09] [/opt/render/project/src/node_modules/mongoose/lib/document.js:~1425] [pc=0x271ea640a5b...
May 16 09:28:43 PM  
May 16 09:28:43 PM  FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
May 16 09:28:43 PM  
May 16 09:28:43 PM  Writing Node.js report to file: report.20200516.155843.35.0.001.json
May 16 09:28:43 PM  Node.js report completed
May 16 09:28:43 PM   1: 0xa02f90 node::Abort() [node]
May 16 09:28:43 PM   2: 0xa033b5 node::OnFatalError(char const*, char const*) [node]
May 16 09:28:43 PM   3: 0xb76ffe v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]
May 16 09:28:43 PM   4: 0xb77379 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]
May 16 09:28:43 PM   5: 0xd23ad5  [node]
May 16 09:28:43 PM   6: 0xd24166 v8::internal::Heap::RecomputeLimits(v8::internal::GarbageCollector) [node]
May 16 09:28:43 PM   7: 0xd309e5 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [node]
May 16 09:28:43 PM   8: 0xd31895 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node]
May 16 09:28:43 PM   9: 0xd3434c v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [node]
May 16 09:28:43 PM  10: 0xcfaf1b v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationType, v8::internal::AllocationOrigin) [node]
May 16 09:28:43 PM  11: 0x103d85e v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [node]
May 16 09:28:43 PM  12: 0x13c03d9  [node]
May 16 09:29:14 PM  ==> Starting service with 'node index.js'
May 16 09:29:25 PM  WARNING: NODE_ENV value of 'production' did not match any deployment config file names.
May 16 09:29:25 PM  WARNING: See https://github.com/lorenwest/node-config/wiki/Strict-Mode
May 16 09:29:26 PM  Connected on port: 10000
May 16 09:29:28 PM  connected to database
May 16 09:29:36 PM  eraProgress 2716



May 16 09:52:22 PM  <--- Last few GCs --->
May 16 09:52:22 PM  
May 16 09:52:22 PM  [36:0x3964790]   575634 ms: Mark-sweep 252.3 (258.0) -> 251.6 (258.0) MB, 932.4 / 0.0 ms  (average mu = 0.175, current mu = 0.179) allocation failure scavenge might not succeed
May 16 09:52:22 PM  [36:0x3964790]   576801 ms: Mark-sweep 252.5 (258.0) -> 251.8 (258.0) MB, 1095.9 / 0.0 ms  (average mu = 0.119, current mu = 0.061) allocation failure scavenge might not succeed
May 16 09:52:22 PM  
May 16 09:52:22 PM  
May 16 09:52:22 PM  <--- JS stacktrace --->
May 16 09:52:22 PM  
May 16 09:52:22 PM  ==== JS stack trace =========================================
May 16 09:52:22 PM  
May 16 09:52:22 PM      0: ExitFrame [pc: 0x13c03d9]
May 16 09:52:22 PM  Security context: 0x1bd74c3c08d1 <JSObject>
May 16 09:52:22 PM      1: emit [0xea8d67623d1] [events.js:~260] [pc=0x12872b82eaae](this=0x0b122e56ee89 <EventEmitter map = 0x2880f160a349>,0x0ea8d6758bb9 <String[#4]: init>)
May 16 09:52:22 PM      2: arguments adaptor frame: 2->1
May 16 09:52:22 PM      3: /* anonymous */ [0x3464dae32c69] [domain.js:~471] [pc=0x12872b84d542](this=0x0b122e56ee89 <EventEmitter map = 0x2880f160a349>)
May 16 09:52:22 PM      4: arguments adaptor frame: 2->0
May 16 09:52:22 PM   ...
May 16 09:52:22 PM  
May 16 09:52:22 PM  FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
May 16 09:52:22 PM  
May 16 09:52:22 PM  Writing Node.js report to file: report.20200516.162222.36.0.001.json
May 16 09:52:22 PM  Node.js report completed
May 16 09:52:22 PM   1: 0xa02f90 node::Abort() [node]
May 16 09:52:22 PM   2: 0xa033b5 node::OnFatalError(char const*, char const*) [node]
May 16 09:52:22 PM   3: 0xb76ffe v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]
May 16 09:52:22 PM   4: 0xb77379 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]
May 16 09:52:22 PM   5: 0xd23ad5  [node]
May 16 09:52:22 PM   6: 0xd24166 v8::internal::Heap::RecomputeLimits(v8::internal::GarbageCollector) [node]
May 16 09:52:22 PM   7: 0xd309e5 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [node]
May 16 09:52:22 PM   8: 0xd31895 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node]
May 16 09:52:22 PM   9: 0xd3434c v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [node]
May 16 09:52:22 PM  10: 0xcfaf1b v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationType, v8::internal::AllocationOrigin) [node]
May 16 09:52:22 PM  11: 0x103d85e v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [node]
May 16 09:52:22 PM  12: 0x13c03d9  [node]


May 16 09:53:24 PM  eraProgress 2955
May 16 09:54:00 PM  
May 16 09:54:00 PM  <--- Last few GCs --->
May 16 09:54:00 PM  
May 16 09:54:00 PM  [36:0x2c08790]    67678 ms: Mark-sweep 252.9 (256.7) -> 252.1 (256.7) MB, 1302.5 / 0.0 ms  (average mu = 0.236, current mu = 0.052) allocation failure scavenge might not succeed
May 16 09:54:00 PM  [36:0x2c08790]    68976 ms: Mark-sweep 252.9 (256.7) -> 252.2 (256.7) MB, 1109.2 / 0.0 ms  (average mu = 0.200, current mu = 0.145) allocation failure scavenge might not succeed
May 16 09:54:00 PM  
May 16 09:54:00 PM  
May 16 09:54:00 PM  <--- JS stacktrace --->
May 16 09:54:00 PM  
May 16 09:54:00 PM  ==== JS stack trace =========================================
May 16 09:54:00 PM  
May 16 09:54:00 PM      0: ExitFrame [pc: 0x13c03d9]
May 16 09:54:00 PM  Security context: 0x28134d4808d1 <JSObject>
May 16 09:54:00 PM      1: /* anonymous */ [0x38ded9cdb389] [/opt/render/project/src/node_modules/mongoose/lib/schema/documentarray.js:~347] [pc=0x1f991880f730](this=0x00ec2eceb441 <DocumentArrayPath map = 0x280d38592ae9>,0x12efec4bc4a9 <JSArray[84]>,0x05849ae0c079 <model map = 0x20a486763c59>,0x3a08e3b80639 <true>,0x3a08e3b804b1 <undefined>,0x3a08e3b804b1 <undefined>)
May 16 09:54:00 PM      2: _init(...
May 16 09:54:00 PM  
May 16 09:54:00 PM  FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
May 16 09:54:00 PM  
May 16 09:54:00 PM  Writing Node.js report to file: report.20200516.162400.36.0.001.json
May 16 09:54:00 PM  Node.js report completed
May 16 09:54:00 PM   1: 0xa02f90 node::Abort() [node]
May 16 09:54:00 PM   2: 0xa033b5 node::OnFatalError(char const*, char const*) [node]
May 16 09:54:00 PM   3: 0xb76ffe v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]
May 16 09:54:00 PM   4: 0xb77379 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]
May 16 09:54:00 PM   5: 0xd23ad5  [node]
May 16 09:54:00 PM   6: 0xd24166 v8::internal::Heap::RecomputeLimits(v8::internal::GarbageCollector) [node]
May 16 09:54:00 PM   7: 0xd309e5 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [node]
May 16 09:54:00 PM   8: 0xd31895 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node]
May 16 09:54:00 PM   9: 0xd3434c v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [node]
May 16 09:54:00 PM  10: 0xcfaf1b v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationType, v8::internal::AllocationOrigin) [node]
May 16 09:54:00 PM  11: 0x103d85e v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [node]
May 16 09:54:00 PM  12: 0x13c03d9  [node]
May 16 09:54:36 PM  ==> Starting service with 'node index.js'
May 16 09:54:45 PM  WARNING: NODE_ENV value of 'production' did not match any deployment config file names.
May 16 09:54:45 PM  WARNING: See https://github.com/lorenwest/node-config/wiki/Strict-Mode
May 16 09:54:46 PM  Connected on port: 10000
May 16 09:54:48 PM  connected to database
May 16 09:54:57 PM  eraProgress 2970

May 16 09:56:45 PM  <--- Last few GCs --->
May 16 09:56:45 PM  
May 16 09:56:45 PM  [35:0x39ba790]   125205 ms: Scavenge 252.7 (257.5) -> 252.0 (258.0) MB, 3.4 / 0.0 ms  (average mu = 0.267, current mu = 0.088) allocation failure
May 16 09:56:45 PM  [35:0x39ba790]   126343 ms: Mark-sweep 252.9 (258.0) -> 252.0 (257.7) MB, 1135.3 / 0.0 ms  (average mu = 0.175, current mu = 0.061) allocation failure scavenge might not succeed
May 16 09:56:45 PM  [35:0x39ba790]   127526 ms: Mark-sweep 252.9 (257.7) -> 252.2 (258.0) MB, 1131.0 / 0.0 ms  (average mu = 0.114, current mu = 0.043) allocation failure scavenge might not succeed
May 16 09:56:45 PM  
May 16 09:56:45 PM  
May 16 09:56:45 PM  <--- JS stacktrace --->
May 16 09:56:45 PM  
May 16 09:56:45 PM  ==== JS stack trace =========================================
May 16 09:56:45 PM  
May 16 09:56:45 PM      0: ExitFrame [pc: 0x13c03d9]
May 16 09:56:45 PM  Security context: 0x23e60dcc08d1 <JSObject>
May 16 09:56:45 PM      1: _init(aka _init) [0x3c7b3b9ee349] [/opt/render/project/src/node_modules/mongoose/lib/document.js:~590] [pc=0x35d74f408a11](this=0x3724314c04b1 <undefined>,3)
May 16 09:56:45 PM      2: init(aka init) [0xeb1dd9ca669] [/opt/render/project/src/node_modules/mongoose/lib/document.js:~576] [pc=0x35d74f3347fe](this=0x3724314c04b1 <undefined>,0x3c7b3b9edba1 <EmbeddedDocument map = 0x...
May 16 09:56:45 PM  
May 16 09:56:45 PM  Writing Node.js report to file: report.20200516.162645.35.0.001.json
May 16 09:56:45 PM  Node.js report completed
May 16 09:56:45 PM   1: 0xa02f90 node::Abort() [node]
May 16 09:56:45 PM   2: 0xa033b5 node::OnFatalError(char const*, char const*) [node]
May 16 09:56:45 PM   3: 0xb76ffe v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]
May 16 09:56:45 PM   4: 0xb77379 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]
May 16 09:56:45 PM   5: 0xd23ad5  [node]
May 16 09:56:45 PM   6: 0xd24166 v8::internal::Heap::RecomputeLimits(v8::internal::GarbageCollector) [node]
May 16 09:56:45 PM   7: 0xd309e5 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [node]
May 16 09:56:45 PM   8: 0xd31895 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node]
May 16 09:56:45 PM   9: 0xd3434c v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [node]
May 16 09:56:45 PM  10: 0xcfaf1b v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationType, v8::internal::AllocationOrigin) [node]
May 16 09:56:45 PM  11: 0x103d85e v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [node]
May 16 09:56:45 PM  12: 0x13c03d9  [node]
@prastut
Copy link
Member Author

prastut commented May 16, 2020

Possible resource to give vantage on the problem:
Automattic/mongoose#2874

@prastut
Copy link
Member Author

prastut commented May 16, 2020

Testing:

  • Multiple ws:// -> make it to single API service -> making only 1 subscription to the node.
  • Instead of 6 hours -> change it to 10 minutes. (Reasonsing: since we know that data updates valuable from YieldScan PoV only happens after 6 hours, we want to increase probability of getting right data)

@prastut
Copy link
Member Author

prastut commented May 16, 2020

|| strategy:

  1. We ready a dummy database with all features. And have it running on local frontend.
  2. Start testing the API with live data.

@prastut prastut changed the title Server Logs Errors Dump Memory Leak Issue Tracker May 17, 2020
@prastut
Copy link
Member Author

prastut commented May 17, 2020

This seems to have been solved by increasing RAM of the server + node.js process.

Though we need to stabilize this further by optimizing our MongoDB<-> Mongoose writes.

Possible solutions here:
https://itnext.io/performance-tips-for-mongodb-mongoose-190732a5d382

@prastut
Copy link
Member Author

prastut commented May 17, 2020

Massive spike though no
image

Though no writes in logs:
image

Possibility that this is read spike

@prastut prastut added +P2 Priority 2 - Medium priority robustness-problem -size-l labels Jun 2, 2020
@prastut prastut added this to the Core Tech Optimization milestone Jun 2, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
-size-l +P2 Priority 2 - Medium priority robustness-problem
Projects
None yet
Milestone
Core Tech Optimization
Development

No branches or pull requests
1 participant
@prastut