RocketChat / Rocket.Chat

The communications platform that puts data protection first.
https://rocket.chat/
Other
40.09k stars 10.35k forks source link

Memory leak #32863

Open ETararenko opened 2 months ago

ETararenko commented 2 months ago

Description:

Memory consumption is growing rapidly due to which the rocket container is often restarted

Steps to reproduce:

Check grow of RAM usage on containers

Expected behavior:

The rocket container works stably without reboots

Actual behavior:

The rocket container reboots few times per day

Server Setup Information:

Client Setup Information

Additional context

image

Relevant logs:

reetp commented 2 months ago

Hi.

Please advise this approximately

Number of Users:

What type of file storage are you using?

Have you tested on latest 6.10.x ?

ETararenko commented 2 months ago

Hello. Number of Users: about 150 What type of file storage are you using? ext4 Have you tested on latest 6.10.x ? No

reetp commented 2 months ago

So what do the logs say when it reboots please?

There must be something there.

Also what are the specs of the host?

ETararenko commented 1 month ago

Specs: processes: 8 memory: 16Gb

{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-24T07:36:08.198527497Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-24T07:36:08.438750734Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-24T07:36:09.062822755Z"}
{"log":"\n","stream":"stderr","time":"2024-07-24T07:36:32.52003097Z"}
{"log":"\u003c--- Last few GCs ---\u003e\n","stream":"stderr","time":"2024-07-24T07:36:32.520071651Z"}
{"log":"\n","stream":"stderr","time":"2024-07-24T07:36:32.520077642Z"}
{"log":"[1:0x559c870] 17404985 ms: Mark-sweep (reduce) 3876.5 (4066.6) -\u003e 3876.0 (4051.6) MB, 5913.8 / 8.9 ms  (average mu = 0.399, current mu = 0.000) last resort GC in old space requested\n","stream":"stderr","time":"2024-07-24T07:36:32.520082582Z"}
{"log":"[1:0x559c870] 17410957 ms: Mark-sweep (reduce) 3876.0 (4044.6) -\u003e 3875.1 (4035.3) MB, 5971.3 / 8.8 ms  (average mu = 0.245, current mu = 0.000) last resort GC in old space requested\n","stream":"stderr","time":"2024-07-24T07:36:32.520087602Z"}
{"log":"\n","stream":"stderr","time":"2024-07-24T07:36:32.520092482Z"}
{"log":"\n","stream":"stderr","time":"2024-07-24T07:36:32.520145254Z"}
{"log":"\u003c--- JS stacktrace ---\u003e\n","stream":"stderr","time":"2024-07-24T07:36:32.520152114Z"}
{"log":"\n","stream":"stderr","time":"2024-07-24T07:36:32.520156854Z"}
{"log":"FATAL ERROR: CALL_AND_RETRY_LAST Allocation failed - JavaScript heap out of memory\n","stream":"stderr","time":"2024-07-24T07:36:32.520161314Z"}
{"log":" 1: 0xa3ad50 node::Abort() [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.520564036Z"}
{"log":" 2: 0x970199 node::FatalError(char const*, char const*) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.520907167Z"}
{"log":" 3: 0xbba90e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.52134139Z"}
{"log":" 4: 0xbbac87 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.521781073Z"}
{"log":" 5: 0xd76ea5  [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.522285298Z"}
{"log":" 6: 0xd894c1 v8::internal::Heap::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.522797854Z"}
{"log":" 7: 0xd4ebfd v8::internal::Factory::AllocateRaw(int, v8::internal::AllocationType, v8::internal::AllocationAlignment) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.523294299Z"}
{"log":" 8: 0xd4ae59 v8::internal::FactoryBase\u003cv8::internal::Factory\u003e::AllocateRawArray(int, v8::internal::AllocationType) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.523789044Z"}
{"log":" 9: 0xd4af14 v8::internal::FactoryBase\u003cv8::internal::Factory\u003e::NewFixedArrayWithFiller(v8::internal::Handle\u003cv8::internal::Map\u003e, int, v8::internal::Handle\u003cv8::internal::Oddball\u003e, v8::internal::AllocationType) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.524330025Z"}
{"log":"10: 0xf775dd v8::internal::Handle\u003cv8::internal::StringTable\u003e v8::internal::HashTable\u003cv8::internal::StringTable, v8::internal::StringTableShape\u003e::New\u003cv8::internal::Isolate\u003e(v8::internal::Isolate*, int, v8::internal::AllocationType, v8::internal::MinimumCapacity) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.524920273Z"}
{"log":"11: 0xf77856 v8::internal::Handle\u003cv8::internal::StringTable\u003e v8::internal::HashTable\u003cv8::internal::StringTable, v8::internal::StringTableShape\u003e::EnsureCapacity\u003cv8::internal::Isolate\u003e(v8::internal::Isolate*, v8::internal::Handle\u003cv8::internal::StringTable\u003e, int, v8::internal::AllocationType) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.525513446Z"}
{"log":"12: 0xf85411 v8::internal::Handle\u003cv8::internal::String\u003e v8::internal::StringTable::LookupKey\u003cv8::internal::InternalizedStringKey\u003e(v8::internal::Isolate*, v8::internal::InternalizedStringKey*) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.526057677Z"}
{"log":"13: 0xf854d6 v8::internal::StringTable::LookupString(v8::internal::Isolate*, v8::internal::Handle\u003cv8::internal::String\u003e) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.526687541Z"}
{"log":"14: 0x10b702e v8::internal::Runtime_HasProperty(int, unsigned long*, v8::internal::Isolate*) [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.527261463Z"}
{"log":"15: 0x1449379  [node]\n","stream":"stderr","time":"2024-07-24T07:36:32.527998131Z"}
{"log":"Some indexes for collection 'rocketchat_uploads' could not be created:\n","stream":"stderr","time":"2024-07-24T07:36:37.697254983Z"}
{"log":"\u0009An existing index has the same name as the requested index. When index names are not specified, they are auto generated and can cause conflicts. Please refer to our documentation. Requested index: { v: 2, key: { rid: 1 }, name: \"rid_1\", sparse: true }, existing index: { v: 2, key: { rid: 1 }, name: \"rid_1\" }\n","stream":"stderr","time":"2024-07-24T07:36:37.697302424Z"}
{"log":"(node:1) UnhandledPromiseRejectionWarning: MongoServerError: An existing index has the same name as the requested index. When index names are not specified, they are auto generated and can cause conflicts. Please refer to our documentation. Requested index: { v: 2, key: { rid: 1 }, name: \"rid_1\", sparse: true }, existing index: { v: 2, key: { rid: 1 }, name: \"rid_1\" }\n","stream":"stderr","time":"2024-07-24T07:36:37.698513886Z"}
{"log":"    at Connection.onMessage (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connection.js:231:30)\n","stream":"stderr","time":"2024-07-24T07:36:37.698545777Z"}
{"log":"    at MessageStream.\u003canonymous\u003e (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connection.js:61:60)\n","stream":"stderr","time":"2024-07-24T07:36:37.698552857Z"}
{"log":"    at MessageStream.emit (events.js:400:28)\n","stream":"stderr","time":"2024-07-24T07:36:37.698558617Z"}
{"log":"    at MessageStream.emit (domain.js:475:12)\n","stream":"stderr","time":"2024-07-24T07:36:37.698585308Z"}
{"log":"    at processIncomingData (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/message_stream.js:125:16)\n","stream":"stderr","time":"2024-07-24T07:36:37.698590488Z"}
{"log":"    at MessageStream._write (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/message_stream.js:33:9)\n","stream":"stderr","time":"2024-07-24T07:36:37.698595579Z"}
{"log":"    at writeOrBuffer (internal/streams/writable.js:358:12)\n","stream":"stderr","time":"2024-07-24T07:36:37.698600609Z"}
{"log":"    at MessageStream.Writable.write (internal/streams/writable.js:303:10)\n","stream":"stderr","time":"2024-07-24T07:36:37.698605449Z"}
{"log":"    at Socket.ondata (internal/streams/readable.js:731:22)\n","stream":"stderr","time":"2024-07-24T07:36:37.698609979Z"}
{"log":"    at Socket.emit (events.js:400:28)\n","stream":"stderr","time":"2024-07-24T07:36:37.698614489Z"}
{"log":"    at Socket.emit (domain.js:475:12)\n","stream":"stderr","time":"2024-07-24T07:36:37.698619039Z"}
{"log":"    at addChunk (internal/streams/readable.js:293:12)\n","stream":"stderr","time":"2024-07-24T07:36:37.698623779Z"}
{"log":"    at readableAddChunk (internal/streams/readable.js:267:9)\n","stream":"stderr","time":"2024-07-24T07:36:37.6986283Z"}
{"log":"    at Socket.Readable.push (internal/streams/readable.js:206:10)\n","stream":"stderr","time":"2024-07-24T07:36:37.698633Z"}
{"log":"    at TCP.onStreamRead (internal/stream_base_commons.js:188:23)\n","stream":"stderr","time":"2024-07-24T07:36:37.69863768Z"}
{"log":"(Use `node --trace-warnings ...` to show where the warning was created)\n","stream":"stderr","time":"2024-07-24T07:36:37.69864219Z"}
{"log":"(node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 2)\n","stream":"stderr","time":"2024-07-24T07:36:37.69864833Z"}
{"log":"(node:1) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.\n","stream":"stderr","time":"2024-07-24T07:36:37.69865411Z"}
{"log":"(node:1) NOTE: We are formalizing our plans to enter AWS SDK for JavaScript (v2) into maintenance mode in 2023.\n","stream":"stderr","time":"2024-07-24T07:36:47.727320209Z"}
{"log":"\n","stream":"stderr","time":"2024-07-24T07:36:47.72735958Z"}
{"log":"Please migrate your code to use AWS SDK for JavaScript (v3).\n","stream":"stderr","time":"2024-07-24T07:36:47.72736436Z"}
{"log":"For more information, check the migration guide at https://a.co/7PzMCcy\n","stream":"stderr","time":"2024-07-24T07:36:47.72736856Z"}
reetp commented 1 month ago

Some indexes for collection 'rocketchat_uploads' could not be created: existing index has the same name as the requested index

First delete the duplicate index and let Rocket.Chat re-create it.

I'd then look for wedged uploads, and also wedged user data downloads created under Account, Preferences, My Data

I have seen those both cause memory issues. There are issues here on both situations IIRC.

Also your logs only start where it runs out of RAM, but not before that.

ETararenko commented 1 month ago

Hello There are many messages like this in the log before restart: {"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-24T07:17:59.919780475Z"} and few like this {"log":"{\"level\":40,\"time\":\"2024-07-24T07:17:59.993Z\",\"pid\":1,\"hostname\":\"fd7b04267032\",\"name\":\"DeprecationWarning\",\"section\":\"API\",\"msg\":\"The parameter \\\"query\\\" in the endpoint \\\"/api/v1/settings.public\\\" is deprecated and will be removed on version 7.0.0\"}\n","stream":"stdout","time":"2024-07-24T07:17:59.994005822Z"} Also this messages after restart

{"log":"LocalStore: cannot set store permissions 0744 (EPERM: operation not permitted, chmod '/app/uploads')\n","stream":"stderr","time":"2024-07-24T12:40:40.733696303Z"}
{"log":"LocalStore: cannot set store permissions 0744 (EPERM: operation not permitted, chmod '/app/uploads')\n","stream":"stderr","time":"2024-07-24T12:40:40.733730914Z"}
{"log":"LocalStore: cannot set store permissions 0744 (EPERM: operation not permitted, chmod '/app/uploads')\n","stream":"stderr","time":"2024-07-24T12:40:40.733735394Z"}

Сan you tell me where to check wedged uploads, in logs?

Thanks.

reetp commented 1 month ago

cannot set store permissions 0744 (EPERM: operation not permitted, chmod '/app/uploads'

You are probably running docker as the wrong user and/or have incorrect permissions on your file store directory.

You need to fix that in your OS.

Search here as there duplicates of this.

ETararenko commented 1 month ago

We have the correct permissions but the wrong owner. Сan you tell me where to check wedged uploads?

reetp commented 1 month ago

In the Mongo DB, but fix your file perms first, restart, and see what happens.

Have a search here as this has come up before (note this is a bug tracker, not general support).

reetp commented 1 month ago

FYI I use Studio3T and you can check collection sizes etc.

ETararenko commented 1 month ago

Hello, The rocket container is still rebooting due to a memory leak Output from log:

{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.300498223Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.300530814Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.300689508Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.300818361Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.300922354Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.301054848Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.301178591Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.488180283Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.488215924Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.57859959Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.578637021Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.578740929Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.57877954Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.578871377Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:12.578921759Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:20.178893197Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:20.761372634Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:20.918897407Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:21.032036907Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:21.032279474Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:21.032380436Z"}
{"log":"(node:1) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 wakeup listeners added to [Connection]. Use emitter.setMaxListeners() to increase limit\n","stream":"stderr","time":"2024-07-25T14:04:21.032862519Z"}
{"log":"\n","stream":"stderr","time":"2024-07-25T14:04:28.925942362Z"}
{"log":"\u003c--- Last few GCs ---\u003e\n","stream":"stderr","time":"2024-07-25T14:04:28.925983793Z"}
{"log":"\n","stream":"stderr","time":"2024-07-25T14:04:28.925989893Z"}
{"log":"[1:0x5fef870] 18265183 ms: Scavenge (reduce) 4004.1 (4101.4) -\u003e 4003.4 (4102.4) MB, 26.7 / 9.7 ms  (average mu = 0.298, current mu = 0.353) allocation failure \n","stream":"stderr","time":"2024-07-25T14:04:28.925995203Z"}
{"log":"[1:0x5fef870] 18265225 ms: Scavenge (reduce) 4004.3 (4101.4) -\u003e 4003.6 (4102.4) MB, 30.9 / 13.4 ms  (average mu = 0.298, current mu = 0.353) allocation failure \n","stream":"stderr","time":"2024-07-25T14:04:28.926000313Z"}
{"log":"[1:0x5fef870] 18265260 ms: Scavenge (reduce) 4004.4 (4104.4) -\u003e 4003.7 (4104.7) MB, 24.1 / 7.8 ms  (average mu = 0.298, current mu = 0.353) allocation failure \n","stream":"stderr","time":"2024-07-25T14:04:28.926005493Z"}
{"log":"\n","stream":"stderr","time":"2024-07-25T14:04:28.926010464Z"}
{"log":"\n","stream":"stderr","time":"2024-07-25T14:04:28.926014844Z"}
{"log":"\u003c--- JS stacktrace ---\u003e\n","stream":"stderr","time":"2024-07-25T14:04:28.926019284Z"}
{"log":"\n","stream":"stderr","time":"2024-07-25T14:04:28.926023694Z"}
{"log":"FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory\n","stream":"stderr","time":"2024-07-25T14:04:28.926028074Z"}
{"log":" 1: 0xa3ad50 node::Abort() [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.932479601Z"}
{"log":" 2: 0x970199 node::FatalError(char const*, char const*) [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.932668806Z"}
{"log":" 3: 0xbba90e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.932677526Z"}
{"log":" 4: 0xbbac87 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.932683036Z"}
{"log":" 5: 0xd76ea5  [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.933407665Z"}
{"log":" 6: 0xd77a2f  [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.933487927Z"}
{"log":" 7: 0xd8586b v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.934133565Z"}
{"log":" 8: 0xd8942c v8::internal::Heap::AllocateRawWithRetryOrFailSlowPath(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.936416935Z"}
{"log":" 9: 0xd57b0b v8::internal::Factory::NewFillerObject(int, bool, v8::internal::AllocationType, v8::internal::AllocationOrigin) [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.936429026Z"}
{"log":"10: 0x10a015f v8::internal::Runtime_AllocateInYoungGeneration(int, unsigned long*, v8::internal::Isolate*) [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.936434486Z"}
{"log":"11: 0x1449379  [node]\n","stream":"stderr","time":"2024-07-25T14:04:28.936792945Z"}
{"log":"(node:1) NOTE: We are formalizing our plans to enter AWS SDK for JavaScript (v2) into maintenance mode in 2023.\n","stream":"stderr","time":"2024-07-25T14:04:50.164943718Z"}
{"log":"\n","stream":"stderr","time":"2024-07-25T14:04:50.164995719Z"}
{"log":"Please migrate your code to use AWS SDK for JavaScript (v3).\n","stream":"stderr","time":"2024-07-25T14:04:50.165001659Z"}
{"log":"For more information, check the migration guide at https://a.co/7PzMCcy\n","stream":"stderr","time":"2024-07-25T14:04:50.16500661Z"}
{"log":"(Use `node --trace-warnings ...` to show where the warning was created)\n","stream":"stderr","time":"2024-07-25T14:04:50.16501169Z"}
{"log":"{\"level\":40,\"time\":\"2024-07-25T14:04:51.654Z\",\"pid\":1,\"hostname\":\"fd7b04267032\",\"name\":\"VoIPService\",\"msg\":\"Voip is not enabled. Cant start the service\"}\n","stream":"stdout","time":"2024-07-25T14:04:51.655048892Z"}
{"log":"{\"level\":51,\"time\":\"2024-07-25T14:04:51.675Z\",\"pid\":1,\"hostname\":\"fd7b04267032\",\"name\":\"Migrations\",\"msg\":\"Not migrating, already at version 304\"}\n","stream":"stdout","time":"2024-07-25T14:04:51.6759475Z"}
{"log":"[2024-07-25T14:04:51.685Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/BROKER: Moleculer v0.14.31 is starting...\n","stream":"stdout","time":"2024-07-25T14:04:51.686361363Z"}
{"log":"[2024-07-25T14:04:51.686Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/BROKER: Namespace: \u003cnot defined\u003e\n","stream":"stdout","time":"2024-07-25T14:04:51.686398804Z"}
{"log":"[2024-07-25T14:04:51.686Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/BROKER: Node ID: f7f86d17-5f6f-4895-9e09-696a351292be\n","stream":"stdout","time":"2024-07-25T14:04:51.686404904Z"}
{"log":"[2024-07-25T14:04:51.687Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/REGISTRY: Strategy: RoundRobinStrategy\n","stream":"stdout","time":"2024-07-25T14:04:51.687871263Z"}
{"log":"[2024-07-25T14:04:51.688Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/REGISTRY: Discoverer: LocalDiscoverer\n","stream":"stdout","time":"2024-07-25T14:04:51.688399217Z"}
{"log":"[2024-07-25T14:04:51.689Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/BROKER: Serializer: EJSONSerializer\n","stream":"stdout","time":"2024-07-25T14:04:51.689297081Z"}
{"log":"[2024-07-25T14:04:51.694Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/BROKER: Validator: FastestValidator\n","stream":"stdout","time":"2024-07-25T14:04:51.695116117Z"}
{"log":"[2024-07-25T14:04:51.696Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/BROKER: Registered 13 middleware(s).\n","stream":"stdout","time":"2024-07-25T14:04:51.69652246Z"}
{"log":"[2024-07-25T14:04:51.697Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/BROKER: Transporter: TcpTransporter\n","stream":"stdout","time":"2024-07-25T14:04:51.697261614Z"}
{"log":"{\"level\":51,\"time\":\"2024-07-25T14:04:51.715Z\",\"pid\":1,\"hostname\":\"fd7b04267032\",\"name\":\"DatabaseWatcher\",\"msg\":\"Using change streams\"}\n","stream":"stdout","time":"2024-07-25T14:04:51.716065952Z"}
{"log":"[2024-07-25T14:04:51.721Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/TRANSIT: Connecting to the transporter...\n","stream":"stdout","time":"2024-07-25T14:04:51.721744384Z"}
{"log":"[2024-07-25T14:04:51.723Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/TRANSPORTER: TCP server is listening on port 38963\n","stream":"stdout","time":"2024-07-25T14:04:51.724085286Z"}
{"log":"[2024-07-25T14:04:51.724Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/TRANSPORTER: UDP Discovery is disabled.\n","stream":"stdout","time":"2024-07-25T14:04:51.724551398Z"}
{"log":"[2024-07-25T14:04:51.724Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/TRANSPORTER: TCP Transporter started.\n","stream":"stdout","time":"2024-07-25T14:04:51.724740273Z"}
{"log":"(node:1) [MONGODB DRIVER] Warning: cursor.count is deprecated and will be removed in the next major version, please use `collection.estimatedDocumentCount` or `collection.countDocuments` instead \n","stream":"stderr","time":"2024-07-25T14:04:51.917183565Z"}
{"log":"[2024-07-25T14:04:52.240Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/REGISTRY: '$node' service is registered.\n","stream":"stdout","time":"2024-07-25T14:04:52.241329752Z"}
{"log":"[2024-07-25T14:04:52.241Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/REGISTRY: 'matrix' service is registered.\n","stream":"stdout","time":"2024-07-25T14:04:52.242389015Z"}
{"log":"[2024-07-25T14:04:52.242Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/$NODE: Service '$node' started.\n","stream":"stdout","time":"2024-07-25T14:04:52.242404115Z"}
{"log":"[2024-07-25T14:04:52.242Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/MATRIX: Service 'matrix' started.\n","stream":"stdout","time":"2024-07-25T14:04:52.242543325Z"}
{"log":"[2024-07-25T14:04:52.242Z] INFO  f7f86d17-5f6f-4895-9e09-696a351292be/BROKER: ✔ ServiceBroker with 2 service(s) started successfully in 532ms.\n","stream":"stdout","time":"2024-07-25T14:04:52.243148715Z"}
{"log":"+-----------------------------------------+\n","stream":"stdout","time":"2024-07-25T14:04:52.383799525Z"}
{"log":"|              SERVER RUNNING             |\n","stream":"stdout","time":"2024-07-25T14:04:52.383835016Z"}
{"log":"+-----------------------------------------+\n","stream":"stdout","time":"2024-07-25T14:04:52.383889002Z"}
{"log":"|                                         |\n","stream":"stdout","time":"2024-07-25T14:04:52.383929304Z"}
{"log":"|  Rocket.Chat Version: 6.7.0             |\n","stream":"stdout","time":"2024-07-25T14:04:52.383934034Z"}
{"log":"|       NodeJS Version: 14.21.3 - x64     |\n","stream":"stdout","time":"2024-07-25T14:04:52.383941614Z"}
{"log":"|      MongoDB Version: 6.0.11            |\n","stream":"stdout","time":"2024-07-25T14:04:52.384099933Z"}
{"log":"|       MongoDB Engine: wiredTiger        |\n","stream":"stdout","time":"2024-07-25T14:04:52.384111134Z"}
{"log":"|             Platform: linux             |\n","stream":"stdout","time":"2024-07-25T14:04:52.384115854Z"}
{"log":"|         Process Port: 3000              |\n","stream":"stdout","time":"2024-07-25T14:04:52.384119664Z"}
{"log":"|             Site URL:   |\n","stream":"stdout","time":"2024-07-25T14:04:52.384123564Z"}
{"log":"|     ReplicaSet OpLog: Enabled           |\n","stream":"stdout","time":"2024-07-25T14:04:52.384127204Z"}
{"log":"|          Commit Hash: 5eb3cbb768        |\n","stream":"stdout","time":"2024-07-25T14:04:52.384131104Z"}
{"log":"|        Commit Branch: HEAD              |\n","stream":"stdout","time":"2024-07-25T14:04:52.384135044Z"}
{"log":"|                                         |\n","stream":"stdout","time":"2024-07-25T14:04:52.384167765Z"}
{"log":"+-----------------------------------------+\n","stream":"stdout","time":"2024-07-25T14:04:52.384171755Z"}
{"log":"{\"level\":40,\"time\":\"2024-07-25T14:05:06.899Z\",\"pid\":1,\"hostname\":\"fd7b04267032\",\"name\":\"DeprecationWarning\",\"section\":\"API\",\"msg\":\"The parameter \\\"query\\\" in the endpoint \\\"/api/v1/settings.public\\\" is deprecated and will be removed on version 7.0.0\"}\n","stream":"stdout","time":"2024-07-25T14:05:06.900073967Z"}
{"log":"The server detected an unauthenticated access to an user avatar. This type of request will soon be blocked by default.\n","stream":"stderr","time":"2024-07-25T14:05:24.648499187Z"}
{"log":"{\"level\":40,\"time\":\"2024-07-25T14:05:40.656Z\",\"pid\":1,\"hostname\":\"fd7b04267032\",\"name\":\"DeprecationWarning\",\"section\":\"API\",\"msg\":\"The parameter \\\"query\\\" in the endpoint \\\"/api/v1/settings.public\\\" is deprecated and will be removed on version 7.0.0\"}\n","stream":"stdout","time":"2024-07-25T14:05:40.656451969Z"}
{"log":"{\"level\":40,\"time\":\"2024-07-25T14:06:02.189Z\",\"pid\":1,\"hostname\":\"fd7b04267032\",\"name\":\"DeprecationWarning\",\"section\":\"API\",\"msg\":\"The parameter \\\"query\\\" in the endpoint \\\"/api/v1/settings.public\\\" is deprecated and will be removed on version 7.0.0\"}\n","stream":"stdout","time":"2024-07-25T14:06:02.189695637Z"}
reetp commented 1 month ago

Can you please upgrade to at least 6.7.6 - there is a security fix you really need to apply soon.

There may be other fixes that address your issue and you should really test this in latest 6.10.x to see if this fixed, though I suspect there is something else going on here that we are not aware of - we would have seen a lot of reports if there really was a leak.

What is your reverse proxy setup?

How many apps do you have installed?

Do you have any custom JS?

reetp commented 1 month ago

It is worth a rest on your error.

https://github.com/RocketChat/Rocket.Chat/issues?q=is%3Aissue+Possible+EventEmitter+memory+leak+detected

eg

https://github.com/RocketChat/Rocket.Chat/issues/19065#issuecomment-781309261

I suspect this is not a actually memory leak but caused by something else that you have going on.

Do you have any webhooks, or other forms of access? iFrames etc?

ETararenko commented 1 month ago

Hello. We only have "Poll" enabled, "GIPHY" disabled and no custom JS. And using nginx as reverse proxy. We will try to upgrade.

reetp commented 1 month ago

Any news?

Did you check collection sizes?

Any other modifications you have made?

ETararenko commented 1 month ago

Hello, rocketchat.rocketchat_uploads | size: 132092503 (0.12 GB) | storageSize: 42401792 (0.04 GB) No other modification.

reetp commented 1 month ago

What version have you upgraded too?

Check the user download collection (can't remember the exact name)

If you run a test VM with a copy of your data and no connections, does it still occur?

Also show us your compose/.env files.

Remove anything sensitive.

ETararenko commented 1 month ago

Version 6.10.1 isn't this rocketchat_uploads? couldn't find any similar ones. There are no problems on the test rocketchat

services:
   rocket:
    container_name: rocket
    image: registry.rocket.chat/rocketchat/rocket.chat:6.10.1
    volumes:
     - /RocketData/:/app/uploads
    environment:
      MONGO_URL: 
      MONGO_OPLOG_URL: 
      ROOT_URL: 
      DEPLOY_METHOD: "docker"
    restart: always
   proxy-rocket:
    container_name: proxy-rocket
    image: nginx:latest
    command: "/bin/sh -c 'while :; do sleep 6h & wait $${!}; nginx -s reload; done & nginx -g \"daemon off;\"'"
    ports:
      - '443:443'
      - '80:80'
    volumes:
      - "/srv/proxy-rocket/conf.d/:/etc/nginx/conf.d/:rw"
      - "/srv/proxy-rocket/ssl/:/etc/nginx/ssl/:rw"
    external_links:
      - "rocket:rocket"
    restart: always
reetp commented 1 month ago

Check

rocketchat_user_data_files

This where data gets stored when a user runs Profile, Preferences, My Data

ETararenko commented 1 month ago

rocketchat.rocketchat_user_data_files | size: 29729 (0.00 GB) | storageSize: 45056 (0.00 GB)

reetp commented 1 month ago

rocketchat.rocketchat_user_data_files | size: 29729 (0.00 GB) | storageSize: 45056 (0.00 GB)

Ok. Another off the list.

Still pretty sure this is a configuration issue rather than bug. If it was a bug we would have seen more than one by now.

On your test VM did you use your current data eg restore from a backup so it has the same data, rather than a fresh install?

ETararenko commented 1 month ago

We use a clone of the virtual machine restored from a backup.

reetp commented 1 month ago

We use a clone of the virtual machine restored from a backup.

Ok.

So the issue isn't Rocket.Chat per se but interaction from a client that triggers it?

We need more logs - restart to restart may help.

ETararenko commented 1 month ago

No new error messages after several restarts. Just FATAL ERROR: Ineffective mark-compacts near heap limit Allocation failed - JavaScript heap out of memory

reetp commented 1 month ago

Your error is a symptom, not a cause.

Set logging to debug and the post your logs.

ETararenko commented 1 month ago

e9168e6b0467a282b80b9c0bacc52987107d3768c90fc2b03960919db285c6bb-json.log image Log from restart to restart. +3 hours on the graph

reetp commented 1 month ago

Thanks for the logs.

I have asked someone from the dev team to take a look.

You'll have to wait and see if we get a response.

reetp commented 1 month ago

Whilst scanning the logs looking for clues....

Error: Push_google_api_credentials is not set

Any reason why you get that error?

Have you got a white labelled app running or using your own push gateway?

CloudWorkspaceAccessTokenEmptyError Failed to communicate with Rocket.Chat Cloud

And these? Networking issues?

Can you post your nginx conf as well please.

ETararenko commented 1 month ago

Error: Push_google_api_credentials is not set We tried to set up pushes through our gateway.

CloudWorkspaceAccessTokenEmptyError
Failed to communicate with Rocket.Chat Cloud

I think its related to empty token. I turned push off today.

server {
       listen         80;
       server_name    http://*****;
       return         301 https://$server_name$request_uri;
}

server {
    listen 443 ssl;
    http2 on;
    server_name https://****;
    client_max_body_size 200M;
    error_log /var/log/nginx/rocketchat.access.log;
    ssl_certificate /etc/nginx/ssl/****.crt;
    ssl_certificate_key /etc/nginx/ssl/****.key;
    ssl_protocols TLSv1.2 TLSv1.3; # don’t use SSLv3 ref: POODLE
    location / {
        proxy_pass http://******:****;
        proxy_set_header Upgrade $http_upgrade;
        proxy_set_header Connection "upgrade";
        proxy_set_header Host $host:$server_port;
#        proxy_set_header Host $http_host;
        proxy_set_header X-Real-IP $remote_addr;
        proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
        proxy_set_header X-Forwarded-Proto https;
        proxy_set_header X-Nginx-Proxy true;
        proxy_redirect off;
        #proxy_connect_timeout 600;
        #proxy_send_timeout 600;
        proxy_read_timeout 200;
        #send_timeout 600;
    }
}
reetp commented 1 month ago

Just to eliminate things can you test with the stock nginx config please (with your own certs) as close as possible to this:

https://docs.rocket.chat/docs/setting-up-client-ssl-certificate-authentication-for-rocketchat

Something like this:

server {
    listen 443 ssl;
    http2 on;
    server_name https://****;
    error_log /var/log/nginx/rocketchat.access.log;
    ssl_certificate /etc/nginx/ssl/****.crt;
    ssl_certificate_key /etc/nginx/ssl/****.key;
    ssl_protocols TLSv1.2 TLSv1.3;

location / {
   if ($ssl_client_verify != SUCCESS) {
     return 403;
   }

    proxy_pass http://******:****;
    proxy_http_version 1.1;
    proxy_set_header Upgrade $http_upgrade;
    proxy_set_header Connection "upgrade";
    proxy_set_header Host $http_host;
    proxy_set_header X-Real-IP $remote_addr;
    proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;
    proxy_set_header X-Forwarded-Proto https;
    proxy_set_header X-Nginx-Proxy true;
    proxy_redirect off;
  }

Also see what your nginx logs say as well.

ETararenko commented 1 month ago

Hello, After disabling push notifications the problem was solved. Thanks for your help

reetp commented 1 month ago

After disabling push notifications the problem was solved.

Not really solved - more 'bypassed' :-) Thanks for letting us know.

I presume you have increasing numbers of push messages being cached somewhere (_raix_push_notifications?) that weren't being sent because your push server was not setup/not setup correctly?

If that is the case - please confirm this.

That should not create an out of memory issue - it would be a bug.

ETararenko commented 1 month ago

Our push server was not setup correctly.

reetp commented 1 month ago

OK thanks

So it is really a bug as it shouldn't crash your server.

I've told the team.