Username changes on LDAP sign-in after upgrading from 3.18 (and server crashes) while forbidden

[Karting06]

Description:

We use a Microsoft Active Directory server for LDAP.
On 3.18.2 (and before), all usernames were synchronised in lowercase.
The synchronised field is sAMAccountName. On the AD, my username would be PvW. On Rocket.Chat, my account username was pvw.

After upgrading to 4.1.2 and log in from a new device, the Rocket.Chat server crashed. After starting it again, I noticed that my username was changed in PvW. My custom avatar was lost too.

If a non-admin user logs in, the username does not change. Strangely, it suddenly changed for non admin users too.
It is forbidden to change the username on our server.

If clicking on a link containing the old username, it will throw an error User not found. However, I see the old avatar.
Private messages also look to be with another than yourself.

Steps to reproduce:

1. Have a server on 3.x with LDAP
2. Upgrade to 4.1.2
3. Log in from a new device.
4. Notice the server crashing
5. Start it again
6. Notice new username and lost avatar

Expected behavior:

Username staying the same. Server not crashing.

Actual behavior:

Username changes and server crashes.
Private messages with myself, look like private messages with another user. Notice that my old avatar is correctly shown. While the placeholder avatar is used for PvW.

Server Setup Information:

• Version of Rocket.Chat Server: 4.1.2
• Operating System: Debian 10
• Deployment Method: tar
• Number of Running Instances: 1
• DB Replicaset Oplog: oplog enabled
• NodeJS Version: 12.18.4
• MongoDB Version: 4.2.17

Client Setup Information

• Desktop App or Browser Version: Doesn't matter
• Operating System: Doesn't matter

Additional context

Most of the users initially synced with LDAP on Rocket.Chat 3.0 (or 3.1).

Relevant logs:

Logs when log in:

Nov 12 14:32:05 rocket rocketchat[32677]: {"level":30,"time":"2021-11-12T13:32:05.076Z","pid":32677,"hostname":"rocket","name":"LDAP","section":"Bind","msg":"Binding UserDN","userDN":"CN=<redacted>,OU=<redacted>,OU=<redacted>,OU=<redacted>,DC=<redacted>,DC=<redacted>"}
Nov 12 14:32:05 rocket rocketchat[32677]: {"level":30,"time":"2021-11-12T13:32:05.138Z","pid":32677,"hostname":"rocket","name":"LDAP","section":"Search","msg":"LDAP Search found 1 entries and loaded the data of 1."}
Nov 12 14:32:05 rocket rocketchat[32677]: {"level":30,"time":"2021-11-12T13:32:05.140Z","pid":32677,"hostname":"rocket","name":"LDAP","section":"Auth","msg":"Authenticating","dn":"CN=Pierre <redacted>,OU=<redacted>,OU=<redacted>,OU=<redacted>,DC=<redacted>,DC=<redacted>"}
Nov 12 14:32:05 rocket rocketchat[32677]: {"level":30,"time":"2021-11-12T13:32:05.144Z","pid":32677,"hostname":"rocket","name":"LDAP","section":"Auth","msg":"Authenticated","dn":"CN=Pierre <redacted>,OU=<redacted>,OU=<redacted>,OU=<redacted>,DC=<redacted>,DC=<redacted>"}
Nov 12 14:32:05 rocket rocketchat[32677]: {"level":30,"time":"2021-11-12T13:32:05.180Z","pid":32677,"hostname":"rocket","name":"LDAP","section":"Search","msg":"LDAP Search found 2 entries and loaded the data of 0."}
Nov 12 14:32:06 rocket rocketchat[32677]: {"level":30,"time":"2021-11-12T13:32:06.439Z","pid":32677,"hostname":"rocket","name":"LDAP","section":"Search","msg":"Idle"}
Nov 12 14:32:06 rocket rocketchat[32677]: {"level":30,"time":"2021-11-12T13:32:06.446Z","pid":32677,"hostname":"rocket","name":"LDAP","section":"Connection","msg":"Disconnecting"}
Nov 12 14:32:08 rocket rocketchat[32677]: {"level":30,"time":"2021-11-12T13:32:08.728Z","pid":32677,"hostname":"rocket","name":"LDAP","section":"Search","msg":"Closed"}
Nov 12 14:32:21 rocket rocketchat[32677]: {"level":35,"time":"2021-11-12T13:32:21.058Z","pid":32677,"hostname":"rocket","name":"Meteor","method":"instances/get","userId":"<redacted>","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/91.0.4472.164 Electron/13.2.2 Safari/537.36","remoteIP":"<redacted>","instanceId":"EvfEHHQsTQKFgTF2w"}
Nov 12 14:32:52 rocket rocketchat[32677]: <--- Last few GCs --->
Nov 12 14:32:52 rocket rocketchat[32677]: [32677:0x4722360]   290926 ms: Scavenge 595.9 (624.3) -> 590.8 (629.3) MB, 178.6 / 1.0 ms  (average mu = 0.980, current mu = 0.979) allocation failure
Nov 12 14:32:52 rocket rocketchat[32677]: [32677:0x4722360]   291329 ms: Scavenge 600.8 (629.3) -> 596.1 (634.3) MB, 145.4 / 1.0 ms  (average mu = 0.980, current mu = 0.979) allocation failure
Nov 12 14:32:52 rocket rocketchat[32677]: [32677:0x4722360]   291843 ms: Scavenge 606.1 (634.3) -> 601.7 (634.5) MB, 268.4 / 1.4 ms  (average mu = 0.980, current mu = 0.979) allocation failure
Nov 12 14:32:52 rocket rocketchat[32677]: <--- JS stacktrace --->
Nov 12 14:32:52 rocket rocketchat[32677]: Cannot get stack trace in GC.
Nov 12 14:32:52 rocket rocketchat[32677]: FATAL ERROR: NewSpace::Rebalance Allocation failed - JavaScript heap out of memory
Nov 12 14:32:52 rocket rocketchat[32677]:  1: 0xa093f0 node::Abort() [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]:  2: 0xa097fc node::OnFatalError(char const*, char const*) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]:  3: 0xb8431e v8::Utils::ReportOOMFailure(v8::internal::Isolate*, char const*, bool) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]:  4: 0xb84699 v8::internal::V8::FatalProcessOutOfMemory(v8::internal::Isolate*, char const*, bool) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]:  5: 0xd31055  [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]:  6: 0xd7aeee  [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]:  7: 0xd7f097 v8::internal::MarkCompactCollector::CollectGarbage() [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]:  8: 0xd3d5c9 v8::internal::Heap::MarkCompact() [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]:  9: 0xd3e2e3 v8::internal::Heap::PerformGarbageCollection(v8::internal::GarbageCollector, v8::GCCallbackFlags) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]: 10: 0xd3ee15 v8::internal::Heap::CollectGarbage(v8::internal::AllocationSpace, v8::internal::GarbageCollectionReason, v8::GCCallbackFlags) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]: 11: 0xd418cc v8::internal::Heap::AllocateRawWithRetryOrFail(int, v8::internal::AllocationType, v8::internal::AllocationOrigin, v8::internal::AllocationAlignment) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]: 12: 0xd082ef v8::internal::Factory::New(v8::internal::Handle<v8::internal::Map>, v8::internal::AllocationType) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]: 13: 0xd12ec5 v8::internal::Factory::NewFunction(v8::internal::Handle<v8::internal::Map>, v8::internal::Handle<v8::internal::SharedFunctionInfo>, v8::internal::Handle<v8::internal::Context>, v8::internal::AllocationType) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]: 14: 0xd13260 v8::internal::Factory::NewFunctionFromSharedFunctionInfo(v8::internal::Handle<v8::internal::SharedFunctionInfo>, v8::internal::Handle<v8::internal::Context>, v8::internal::AllocationType) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]: 15: 0xba6391 v8::ScriptCompiler::Compile(v8::Local<v8::Context>, v8::ScriptCompiler::Source*, v8::ScriptCompiler::CompileOptions, v8::ScriptCompiler::NoCacheReason) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]: 16: 0xba6476 v8::Script::Compile(v8::Local<v8::Context>, v8::Local<v8::String>, v8::ScriptOrigin*) [/usr/local/bin/node]
Nov 12 14:32:52 rocket rocketchat[32677]: 17: 0x7f1960260065 uni::fixStackLimit(v8::Isolate*, v8::Local<v8::Context>) [/opt/Rocket.Chat/programs/server/node_modules/fibers/bin/linux-x64-72-glibc/fibers.node]
Nov 12 14:32:52 rocket rocketchat[32677]: 18: 0x7f1960261f9e Fiber::RunFiber(void**) [/opt/Rocket.Chat/programs/server/node_modules/fibers/bin/linux-x64-72-glibc/fibers.node]
Nov 12 14:32:52 rocket rocketchat[32677]: 19: 0x7f1960262785 Coroutine::trampoline(void*) [/opt/Rocket.Chat/programs/server/node_modules/fibers/bin/linux-x64-72-glibc/fibers.node]
Nov 12 14:32:52 rocket rocketchat[32677]: 20: 0x7f1960263177  [/opt/Rocket.Chat/programs/server/node_modules/fibers/bin/linux-x64-72-glibc/fibers.node]
Nov 12 14:32:52 rocket systemd[1]: rocketchat.service: Main process exited, code=killed, status=6/ABRT
Nov 12 14:32:52 rocket systemd[1]: rocketchat.service: Failed with result 'signal'.

[ankar84]

could be related to #23093 but probably a much more critical problem.

[Gummikavalier]

Also related: #12116

Possibly related: #22832

[Karting06]

@Gummikavalier, yeah it looks like #12116 has been fixed which leads to this problem...

It's not related to #23093 because the problem is the username not the real name.
Not sure for #22832, because the username just gets renamed. No new account is created.