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.

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

Large log messages cause process crash / OOM #50

Open
johnpeb opened this issue Sep 18, 2020 · 1 comment
Open

Large log messages cause process crash / OOM #50

johnpeb opened this issue Sep 18, 2020 · 1 comment

Comments

@johnpeb
Copy link
Contributor

johnpeb commented Sep 18, 2020

Overly large log messages cause the node process to crash with out of memory.

This happens frequently:

logzio-logger error: Error: There was a problem with the request.
Response: 413: 413 - "" Error: There was a problem with the request.
Response: 413: 413 - ""
    at /var/app/current/node_modules/logzio-nodejs/lib/logzio-nodejs.js:305:42
    at tryCatcher (/var/app/current/node_modules/bluebird/js/release/util.js:16:23)
    at Promise._settlePromiseFromHandler (/var/app/current/node_modules/bluebird/js/release/promise.js:512:31)
    at Promise._settlePromise (/var/app/current/node_modules/bluebird/js/release/promise.js:569:18)
    at Promise._settlePromise0 (/var/app/current/node_modules/bluebird/js/release/promise.js:614:10)
    at Promise._settlePromises (/var/app/current/node_modules/bluebird/js/release/promise.js:689:18)
    at Async._drainQueue (/var/app/current/node_modules/bluebird/js/release/async.js:133:16)
    at Async._drainQueues (/var/app/current/node_modules/bluebird/js/release/async.js:143:10)
    at Immediate.Async.drainQueues [as _onImmediate] (/var/app/current/node_modules/bluebird/js/release/async.js:17:14)
    at processImmediate (internal/timers.js:439:21)

Then at the end this. Presumably, the failed send is retained for retry which is not appropriate if the message is too large and will not index anyway if it does get through to logz.

<--- Last few GCs --->

[31461:0x35d6440]   306124 ms: Mark-sweep 964.0 (982.1) -> 962.9 (982.1) MB, 53.0 / 0.0 ms  (average mu = 0.302, current mu = 0.380) allocation failure scavenge might not succeed
[31461:0x35d6440]   306197 ms: Mark-sweep 964.0 (982.1) -> 962.8 (982.1) MB, 56.2 / 0.0 ms  (average mu = 0.271, current mu = 0.236) allocation failure scavenge might not succeed


<--- JS stacktrace --->

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

    0: ExitFrame [pc: 0x1376259]
Security context: 0x2f31614008a1 <JSObject>
    1: split [0x2f316140d031](this=0x1e0baa1324f1 <String[#9]: _bsontype>,0x035ecffc38e1 <String[#1]: .>)
    2: clone(aka clone) [0xfa144281c09] [/var/app/current/node_modules/mongoose/lib/helpers/clone.js:~29] [pc=0x3681f9aaa5de](this=0x035ecffc04a9 <undefined>,0x035ecffc0631 <true>,0x035ecffc04a9 <undefined>,0x035ecffc04a9 <undefined>)
    3: clone(aka clone) ...

FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory
 1: 0x9dab70 node::Abort() [node]
 2: 0x9dbd26 node::OnFatalError(char const*, char const*) [node]
 3: 0xb3b18e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]
 4: 0xb3b509 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]
 5: 0xce68a5  [node]
 6: 0xce6f36 v8::internal::Heap::RecomputeLimits(v8::internal::GarbageCollector) [node]
 7: 0xcf2dca v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [node]
 8: 0xcf3cd5 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node]
 9: 0xcf66e8 v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationAlignment) [node]
10: 0xcbccac v8::internal::Factory::AllocateRawWithAllocationSite(v8::internal::Handle<v8::internal::Map>, v8::internal::AllocationType, v8::internal::Handle<v8::internal::AllocationSite>) [node]
11: 0xcc9a54 v8::internal::Factory::NewJSArrayWithUnverifiedElements(v8::internal::Handle<v8::internal::FixedArrayBase>, v8::internal::ElementsKind, int, v8::internal::AllocationType) [node]
12: 0xcc9b81 v8::internal::Factory::NewJSArrayWithElements(v8::internal::Handle<v8::internal::FixedArrayBase>, v8::internal::ElementsKind, int, v8::internal::AllocationType) [node]
13: 0x101f492 v8::internal::Runtime_StringSplit(int, unsigned long*, v8::internal::Isolate*) [node]
14: 0x1376259  [node]
@AlonMiz
Copy link
Contributor

AlonMiz commented Sep 22, 2020

internally we use https://www.npmjs.com/package/rough-object-size to watch out from huge messages
we use it like that:

// 1048576 * 0.5 = 0.5MB
function logSize({ maxLogSizeBytes = 1048576 * 0.5 } = {}) {
  return function logSizeLog(log) {
    log.logSize = roughObjectSize(log);

    if (maxLogSizeBytes < log.logSize) {
      log.logObjectKeys = Object.keys(log);
      log.message = 'Log exceeded the max bytes size';
      log.maxLogSize = maxLogSizeBytes;
    }

    return log;
  };
}


Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants