3.11.1: createDirectMessage & getRoomByTypeAndName Exception: Invalid User

Description:

Following a major upgrade from 2.4 to 3.11.1, we started seeing several errors crop up in the log, listed as "[error-invalid-user]". While there is some semblance of a stack trace, there's little to no additional information to explain which user is generating this issue; or from what channel this issue is occurring in...just that there's a problem.

I've looked through our users both in RC's administration panel, as well as directly in MongoDB; and nothing is jumping out at me as out of place or misconfigured.

Steps to reproduce:

1. Upgrade from (manual) 2.4 to (manual) 3.11.1
2. Check Rocket.Chat logs

• The errors do not always appear immediately

Expected behavior:

No exceptions -- or at the very least, a little more detail in the exception log.

Actual behavior:

I've redacted the stack trace in this section for brevity. Actual logs will be listed in full in the 'Relevant Logs' section.

I20210421-14:09:58.172(-4) Exception while invoking method getRoomByTypeAndName Error: Invalid user [error-invalid-user]
I20210421-14:09:58.431(-4) Exception while invoking method createDirectMessage Error: Invalid user [error-invalid-user]

While I do not have the exception to share, I have also seen similar messages for the method "loadMissedMessages" in the recent past as well.

Server Setup Information:

• Version of Rocket.Chat Server: 3.11.1
• Operating System: CentOS 7
• Deployment Method: tar/manual
• Number of Running Instances: 1
• DB Replicaset Oplog: Yes (rs01)
• NodeJS Version: v12.18.4
• MongoDB Version: 4.0.24 / mmapv1 (oplog Enabled)

Client Setup Information

N/A

Additional context

We were not seeing these exceptions prior to our upgrade. I'm assuming something with these methods/functions changed during the year we remained on the old build. Additionally, here are some related issues I was able to locate in the tracker:

• #19703
• #18917

We have not yet tried on the latest release to see if the issue still arises, though I fear it may still occur.

Relevant logs:

Rocket.Chat.Electron > Administration > View Logs

Exception @ Method: getRoomByTypeAndName

I20210421-14:09:58.172(-4) Exception while invoking method getRoomByTypeAndName Error: Invalid user [error-invalid-user]
	at MethodInvocation.getRoomByTypeAndName (server/publications/room/index.js:42:10)
	at MethodInvocation.methodsMap.<computed> (app/lib/server/lib/debug.js:76:34)
	at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12)
	at packages/ddp-server/livedata_server.js:1689:15
	at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
	at packages/ddp-server/livedata_server.js:1687:36
	at new Promise (<anonymous>)
	at Server.applyAsync (packages/ddp-server/livedata_server.js:1686:12)
	at Server.apply (packages/ddp-server/livedata_server.js:1625:26)
	at Server.call (packages/ddp-server/livedata_server.js:1607:17)
	at Object.post (app/api/server/v1/misc.js:263:26)
	at app/api/server/api.js:394:82
	at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
	at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
	at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
	at packages/nimble_restivus/lib/route.coffee:59:33
	at packages/simple_json-routes.js:98:9  => awaited here:
	at Promise.await (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:60:12)
	at Server.apply (packages/ddp-server/livedata_server.js:1638:22)
	at Server.call (packages/ddp-server/livedata_server.js:1607:17)
	at Object.post (app/api/server/v1/misc.js:263:26)
	at app/api/server/api.js:394:82
	at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
	at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
	at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
	at packages/nimble_restivus/lib/route.coffee:59:33
	at packages/simple_json-routes.js:98:9

Exception @ Method: createDirectMessage

I20210421-14:09:58.431(-4) Exception while invoking method createDirectMessage Error: Invalid user [error-invalid-user]
	at MethodInvocation.createDirectMessage (server/methods/createDirectMessage.js:16:10)
	at MethodInvocation.methodsMap.<computed> (app/lib/server/lib/debug.js:76:34)
	at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12)
	at packages/ddp-server/livedata_server.js:1689:15
	at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
	at packages/ddp-server/livedata_server.js:1687:36
	at new Promise (<anonymous>)
	at Server.applyAsync (packages/ddp-server/livedata_server.js:1686:12)
	at Server.apply (packages/ddp-server/livedata_server.js:1625:26)
	at Server.call (packages/ddp-server/livedata_server.js:1607:17)
	at Object.post (app/api/server/v1/misc.js:263:26)
	at app/api/server/api.js:394:82
	at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
	at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
	at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
	at packages/nimble_restivus/lib/route.coffee:59:33
	at packages/simple_json-routes.js:98:9  => awaited here:
	at Promise.await (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:60:12)
	at Server.apply (packages/ddp-server/livedata_server.js:1638:22)
	at Server.call (packages/ddp-server/livedata_server.js:1607:17)
	at Object.post (app/api/server/v1/misc.js:263:26)
	at app/api/server/api.js:394:82
	at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
	at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
	at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
	at packages/nimble_restivus/lib/route.coffee:59:33
	at packages/simple_json-routes.js:98:9 

Journalctl -xeu rocketchat

Exception @ Method getRoomByNameAndType

Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]: Exception while invoking method getRoomByTypeAndName Error: Invalid user [error-invalid-user]
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at MethodInvocation.getRoomByTypeAndName (server/publications/room/index.js:42:10)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at MethodInvocation.methodsMap.<computed> (app/lib/server/lib/debug.js:76:34)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/ddp-server/livedata_server.js:1689:15
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/ddp-server/livedata_server.js:1687:36
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at new Promise (<anonymous>)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Server.applyAsync (packages/ddp-server/livedata_server.js:1686:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Server.apply (packages/ddp-server/livedata_server.js:1625:26)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Server.call (packages/ddp-server/livedata_server.js:1607:17)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Object.post (app/api/server/v1/misc.js:263:26)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at app/api/server/api.js:394:82
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/nimble_restivus/lib/route.coffee:59:33
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/simple_json-routes.js:98:9
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]: => awaited here:
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Promise.await (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:60:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Server.apply (packages/ddp-server/livedata_server.js:1638:22)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Server.call (packages/ddp-server/livedata_server.js:1607:17)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Object.post (app/api/server/v1/misc.js:263:26)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at app/api/server/api.js:394:82
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/nimble_restivus/lib/route.coffee:59:33
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/simple_json-routes.js:98:9

Exception @ Method createDirectMessage

Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]: Exception while invoking method createDirectMessage Error: Invalid user [error-invalid-user]
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at MethodInvocation.createDirectMessage (server/methods/createDirectMessage.js:16:10)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at MethodInvocation.methodsMap.<computed> (app/lib/server/lib/debug.js:76:34)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at maybeAuditArgumentChecks (packages/ddp-server/livedata_server.js:1771:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/ddp-server/livedata_server.js:1689:15
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/ddp-server/livedata_server.js:1687:36
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at new Promise (<anonymous>)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Server.applyAsync (packages/ddp-server/livedata_server.js:1686:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Server.apply (packages/ddp-server/livedata_server.js:1625:26)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Server.call (packages/ddp-server/livedata_server.js:1607:17)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Object.post (app/api/server/v1/misc.js:263:26)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at app/api/server/api.js:394:82
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/nimble_restivus/lib/route.coffee:59:33
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/simple_json-routes.js:98:9
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]: => awaited here:
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Promise.await (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:60:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Server.apply (packages/ddp-server/livedata_server.js:1638:22)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Server.call (packages/ddp-server/livedata_server.js:1607:17)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Object.post (app/api/server/v1/misc.js:263:26)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at app/api/server/api.js:394:82
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1234:12)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Object._internalRouteActionHandler [as action] (app/api/server/api.js:394:39)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at Route.share.Route.Route._callEndpoint (packages/nimble_restivus/lib/route.coffee:150:32)
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/nimble_restivus/lib/route.coffee:59:33
Apr 22 09:36:08 chat228.wtcox.com rocketchat[1030]:		at packages/simple_json-routes.js:98:9

Start with the stack-trace entry points in server/publications/room/index.js and server/methods/createDirectMessage.js, then review the related loadMissedMessages path mentioned in the report. Reproduce the post-upgrade Invalid user errors and determine which user or channel context is missing; done means the affected methods no longer raise unexplained errors or provide more actionable log detail.