Kotahi crash -- out of memory?
A crash observed on kotahidev. We navigated to the manuscripts page and got just the left menu and a spinner where the manuscripts table was supposed to be. Refreshing didn't fix it.
We had these logs:
server_1 | info: Bad auth token
server_1 | error: Cannot read property 'replace' of undefined message=Cannot read property 'replace' of undefined, locations=[line=28, column=3], path=[convertToJats], code=INTERNAL_SERVER_ERROR, stacktrace=[TypeError: Cannot read property 'replace' of undefined, at removeIllegalCharacters (/home/node/app/server/utils/jatsUtils.js:174:50), at htmlToJats (/home/node/app/server/utils/jatsUtils.js:220:10), at makeFootnotesSection (/home/node/app/server/utils/jatsUtils.js:436:39), at makeJats (/home/node/app/server/utils/jatsUtils.js:742:42), at jatsHandler (/home/node/app/server/jatsexport/graphql.js:55:20), at runMicrotasks (<anonymous>), at processTicksAndRejections (internal/process/task_queues.js:97:5), at async convertToJats (/home/node/app/server/jatsexport/graphql.js:73:31), at async middleware (/home/node/app/node_modules/@coko/server/node_modules/graphql-shield/dist/generator.js:30:24)]
server_1 | info: ::ffff:172.20.0.7 - - [09/Mar/2022:06:28:09 +0000] "POST /graphql HTTP/1.1" 200 227480 "http://kotahidev.cloud68.co/kotahi/versions/17c80e22-5b4a-40d3-aa61-f03dffd0ee18/production" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/99.0.4844.51 Safari/537.36"
server_1 |
server_1 | info: Bad auth token
server_1 | info: Bad auth token
server_1 | info: Bad auth token
server_1 | info: ::ffff:172.20.0.7 - - [09/Mar/2022:06:28:12 +0000] "POST /graphql HTTP/1.1" 200 46543 "http://kotahidev.cloud68.co/kotahi/admin/manuscripts" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/99.0.4844.51 Safari/537.36"
server_1 |
server_1 | info: ::ffff:172.20.0.7 - - [09/Mar/2022:06:28:14 +0000] "POST /graphql HTTP/1.1" 200 8700 "http://kotahidev.cloud68.co/kotahi/admin/manuscripts" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/99.0.4844.51 Safari/537.36"
server_1 |
client_1 | [HPM] Error occurred while trying to proxy request /graphql from kotahidev.cloud68.co to http://server:3000 (ECONNRESET) (https://nodejs.org/api/errors.html#errors_common_system_errors)
client_1 | [HPM] Error occurred while trying to proxy request /graphql from kotahidev.cloud68.co to http://server:3000 (ECONNRESET) (https://nodejs.org/api/errors.html#errors_common_system_errors)
client_1 | [HPM] Error occurred while trying to proxy request /graphql from kotahidev.cloud68.co to http://server:3000 (ECONNRESET) (https://nodejs.org/api/errors.html#errors_common_system_errors)
server_1 |
server_1 | <--- Last few GCs --->
server_1 |
server_1 | [52:0x3659f60] 15825903 ms: Scavenge 2043.9 (2052.3) -> 2042.4 (2052.5) MB, 9.6 / 0.0 ms (average mu = 0.159, current mu = 0.120) allocation failure
server_1 | [52:0x3659f60] 15825934 ms: Scavenge 2044.1 (2052.5) -> 2042.6 (2052.5) MB, 9.7 / 0.0 ms (average mu = 0.159, current mu = 0.120) allocation failure
server_1 | [52:0x3659f60] 15825965 ms: Scavenge 2044.3 (2052.5) -> 2042.8 (2052.8) MB, 9.7 / 0.0 ms (average mu = 0.159, current mu = 0.120) allocation failure
server_1 |
server_1 |
server_1 | <--- JS stacktrace --->
server_1 |
server_1 | ==== JS stack trace =========================================
server_1 |
server_1 | 0: ExitFrame [pc: 0x140a7f9]
server_1 | 1: StubFrame [pc: 0x138ed76]
server_1 | Security context: 0x3cc3032408d1 <JSObject>
server_1 | 2: replace [0x3cc30324cc71](this=0x220f5dc06651 <Very long string[49398]>,0x29a0d2aea329 <String[587]: <footnote id="0f047ff5-ae57-4f2c-a11f-5b5ee075b09e"/></p><p class="paragraph"><em>Methods: </em>A web survey inquiring about depressive symptoms, help-seeking, and barriers to mental healthcare was conducted. Depressive sympt...
server_1 |
server_1 | FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memoryserver_1 | 1: 0xa18150 node::Abort() [/usr/local/bin/node]
server_1 | 2: 0xa1855c node::OnFatalError(char const*, char const*) [/usr/local/bin/node]
server_1 | 3: 0xb9705e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/usr/local/bin/node]
server_1 | 4: 0xb973d9 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/usr/local/bin/node]
server_1 | 5: 0xd54655 [/usr/local/bin/node]
server_1 | 6: 0xd54ce6 v8::internal::Heap::RecomputeLimits(v8::internal::GarbageCollector) [/usr/local/bin/node]
server_1 | 7: 0xd615a5 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/usr/local/bin/node]
server_1 | 8: 0xd62455 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/usr/local/bin/node]
server_1 | 9: 0xd64f0c v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/usr/local/bin/node]
server_1 | 10: 0xd3343d v8::internal::Factory::NewRawTwoByteString(int, v8::internal::AllocationType) [/usr/local/bin/node]
server_1 | 11: 0xf73735 v8::internal::String::SlowFlatten(v8::internal::Isolate*, v8::internal::Handle<v8::internal::ConsString>, v8::internal::AllocationType) [/usr/local/bin/node]
server_1 | 12: 0xb962bb v8::internal::String::Flatten(v8::internal::Isolate*, v8::internal::Handle<v8::internal::String>, v8::internal::AllocationType) [/usr/local/bin/node]
server_1 | 13: 0xf758b4 v8::internal::String::IndexOf(v8::internal::Isolate*, v8::internal::Handle<v8::internal::String>, v8::internal::Handle<v8::internal::String>, int) [/usr/local/bin/node]
server_1 | 14: 0x10ac91b v8::internal::Runtime_StringIndexOfUnchecked(int, unsigned long*, v8::internal::Isolate*) [/usr/local/bin/node]
server_1 | 15: 0x140a7f9 [/usr/local/bin/node]
db_1 | 2022-03-09 06:33:19.617 UTC [946] LOG: could not receive data from client: Connection reset by peer
server_1 | [nodemon] app crashed - waiting for file changes before starting...
client_1 | [HPM] Error occurred while trying to proxy request /subscriptions from kotahidev.cloud68.co to ws://server:3000 (ECONNRESET) (https://nodejs.org/api/errors.html#errors_common_system_errors)
db_1 | 2022-03-09 06:33:19.680 UTC [929] LOG: could not receive data from client: Connection reset by peer
client_1 | events.js:291
client_1 | throw er; // Unhandled 'error' event
client_1 | ^
client_1 |
client_1 | Error: write EPIPE
client_1 | at afterWriteDispatched (internal/stream_base_commons.js:156:25)
client_1 | at writeGeneric (internal/stream_base_commons.js:147:3)
client_1 | at Socket._writeGeneric (net.js:787:11)
client_1 | at Socket._write (net.js:799:8)
client_1 | at doWrite (_stream_writable.js:403:12)
client_1 | at writeOrBuffer (_stream_writable.js:387:5)
client_1 | at Socket.Writable.write (_stream_writable.js:318:11)
client_1 | at Socket.Writable.end (_stream_writable.js:585:10)
client_1 | at Socket.end (net.js:591:31)
client_1 | at ProxyServer.defaultErrorHandler (/home/node/app/node_modules/http-proxy-middleware/lib/handlers.js:76:7)
client_1 | at ProxyServer.emit (/home/node/app/node_modules/http-proxy/node_modules/eventemitter3/index.js:204:33)
client_1 | at ClientRequest.onOutgoingError (/home/node/app/node_modules/http-proxy/lib/http-proxy/passes/ws-incoming.js:157:16)
client_1 | at ClientRequest.emit (events.js:314:20)
client_1 | at Socket.socketErrorListener (_http_client.js:427:9)
client_1 | at Socket.emit (events.js:314:20)
client_1 | at emitErrorNT (internal/streams/destroy.js:92:8)
client_1 | Emitted 'error' event on Socket instance at:
client_1 | at errorOrDestroy (internal/streams/destroy.js:108:12)
client_1 | at onwriteError (_stream_writable.js:418:5)
client_1 | at onwrite (_stream_writable.js:445:5)
client_1 | at internal/streams/destroy.js:50:7
client_1 | at Socket._destroy (net.js:680:5)
client_1 | at Socket.destroy (internal/streams/destroy.js:38:8)
client_1 | at afterWriteDispatched (internal/stream_base_commons.js:156:17)
client_1 | at writeGeneric (internal/stream_base_commons.js:147:3)
client_1 | [... lines matching original stack trace ...]
client_1 | at ProxyServer.defaultErrorHandler (/home/node/app/node_modules/http-proxy-middleware/lib/handlers.js:76:7) {
client_1 | errno: 'EPIPE',
client_1 | code: 'EPIPE',
client_1 | syscall: 'write'
client_1 | }
db_1 | 2022-03-09 06:33:19.691 UTC [929] LOG: unexpected EOF on client connection with an open transaction
kotahi_client_1 exited with code 1
The first "error: Cannot read property 'replace'" may have occurred before or after the crash, not sure. The "[HPM] Error occurred while trying to proxy request" errors appeared at the time of the crash, and then the "Last few GCs" came a few minutes later.