Errors [error-invalid-user] and [error-invalid-room]

ankar84 commented 3 years ago

Description:

Since I enabled Use REST instead of websocket for Meteor calls in Admin UI - General - REAT API (and I don't know why it was disabled, because default seems to be enabled state) I get in logs a lot of useless entries like this:

Exception while invoking method getRoomByTypeAndName Error: Invalid user [error-invalid-user]
Exception while invoking method getRoomByTypeAndName Error: Invalid room [error-invalid-room]

They a really useless because don't give information how to fix them - they don't mention which user or room is currently invalid. But instead of mention user or room it shows useless stack trace which is flooding our logs because we using docker deployment and that traces generates a lot of log entries.

Steps to reproduce:

Enable Use REST instead of websocket for Meteor calls in Admin UI - General - REST API
Check logs

Expected behavior:

Or clean logs or mention what user or room is invalid actually to handle that and fix it.

Actual behavior:

Flooded logs and (maybe) bad influence to server general load which could lead to instability.

Server Setup Information:

Version of Rocket.Chat Server: 3.15.0
Operating System: CentOS7
Deployment Method: docker
Number of Running Instances: 25
DB Replicaset Oplog: Enabled
NodeJS Version: 12.22.1
MongoDB Version: 4.2.14 WiredTiger

Client Setup Information

Desktop App or Browser Version: 3.2.2
Operating System: Windows 10

Additional context

Could be related to https://github.com/RocketChat/Rocket.Chat/issues/21182 in stability aspect

Relevant logs:


I20210606-01:21:49.596(0) Exception while invoking method getRoomByTypeAndName Error: Invalid user [error-invalid-user]     at MethodInvocation.getRoomByTypeAndName (server/publications/room/index.js:43: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 (/app/bundle/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 
I20210606-03:11:20.945(0) Exception while invoking method getRoomByTypeAndName Error: Invalid user [error-invalid-user]     at MethodInvocation.getRoomByTypeAndName (server/publications/room/index.js:43: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 (/app/bundle/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 
I20210606-03:11:20.983(0) 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 (/app/bundle/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 
I20210605-23:10:16.745(0) Exception while invoking method loadMissedMessages Error: Invalid user [error-invalid-user]     at MethodInvocation.canAccessRoom (server/methods/canAccessRoom.js:51: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 MethodInvocation.loadMissedMessages (server/methods/loadMissedMessages.js:13:15)     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 (/app/bundle/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 MethodInvocation.loadMissedMessages (server/methods/loadMissedMessages.js:13:15)     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 (/app/bundle/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 
I20210605-23:10:16.864(0) Exception while invoking method loadMissedMessages Error: Invalid user [error-invalid-user]     at MethodInvocation.canAccessRoom (server/methods/canAccessRoom.js:51: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 MethodInvocation.loadMissedMessages (server/methods/loadMissedMessages.js:13:15)     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 (/app/bundle/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 MethodInvocation.loadMissedMessages (server/methods/loadMissedMessages.js:13:15)     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 (/app/bundle/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 while invoking method getRoomByTypeAndName Error: Invalid room [error-invalid-room]

johncrisp commented 3 years ago

Anton,

Can you edit that to say REST not REAT ?

ankar84 commented 3 years ago

Anton,

Can you edit that to say REST not REAT ?

Done! One important note - we are using KeyCloak for authentication and after update to 3.15.0 I have a couple users request about Invalid user error on a blank gray background of RC.Electron application Restart of client and CTRL+R doesn't help, only recreating our server connection (delete - add)

emikolajczak commented 3 years ago

Hi, I have also observe this Errors [error-invalid-user] and [error-invalid-room] errors in logs,

EDIT: Potentialy related with https://github.com/RocketChat/Rocket.Chat/issues/21735

dkoo761 commented 3 years ago

I can reproduce this error....

Exception while invoking method getRoomByTypeAndName Error: Invalid room [error-invalid-room]

Steps to reproduce:

Go to the directory
Click on the Users tab
Click on a user that I have never clicked on (or had a DM with) before
In this case, it tries to load the user using the /direct/{username} URL which throws the exception and then it creates a new room and opens it for the user and redirects to the /direct/{roomId} URL

dkoo761 commented 3 years ago

Actually any time a user opens a DM window with another user for the first time, this exception seems to occur. Not just when you click on the user from the directory page as I mentioned above.

tmartincpp commented 3 years ago

We are having this error too but I can't reproduce everytime, it seems to happen randomly when you want to send a DM to a user for the first time.

Server Setup Information:

Version of Rocket.Chat Server: 3.16.1
Operating System: Debian Buster
Deployment Method: build from sources
Number of Running Instances: 2
DB Replicaset Oplog: yes
NodeJS Version: 12.18.4
MongoDB Version: 4.0.25

Client Setup Information

Desktop App: 3.2.3 or 3.1.1
Operating System: Debian Buster

Additional context

REST API is enabled but I don't know if this is relevant. Our users are created and authenticated through LDAP.

Only way to have access to RC again is to refresh the page/application (CTRL+R).

Relevant logs:

Exception while invoking method getRoomByTypeAndName Error: Invalid room [error-invalid-room]
    at MethodInvocation.getRoomByTypeAndName (server/publications/room/index.js:51: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 (/rocketchat/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 while invoking method createDirectMessage Error: Invalid user [error-invalid-user]
    at server/methods/createDirectMessage.js:44:11
    at Array.map (<anonymous>)
    at MethodInvocation.createDirectMessage (server/methods/createDirectMessage.js:35:74)
    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 (/rocketchat/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

ankar84 commented 3 years ago

Still exist in 3.16.3

ankar84 commented 3 years ago

At 3.16.3 I see a lot of these:

server.js:204 System ➔ error Error starting video call: Error: error-invalid-room
Exception while invoking method jitsi:updateTimeout Error: error-invalid-room [error-starting-video-call]
Exception while invoking method getRoomByTypeAndName Error: Invalid room [error-invalid-room]
Exception while invoking method createDirectMessage Error: Invalid user [error-invalid-user]
Exception while invoking method roomNameExists Error: Error, too many requests. Please slow down. You must wait 2 seconds before trying again. [too-many-requests]
Exception while invoking method jitsi:updateTimeout Error: error-invalid-room [error-starting-video-call]
server.js:204 System ➔ error Error starting video call: Error: error-invalid-room

ankar84 commented 3 years ago

My guess, that all that invalid-room and invalid-user could be related to https://github.com/RocketChat/Rocket.Chat/issues/21237 And could be caused with users start conversations with disabled (deactivated) users. Previously disactivated users chats become read-only and no one can write there. Now all that chats looks like regular chats.

tmartincpp commented 3 years ago

My guess, that all that invalid-room and invalid-user could be related to #21237 And could be caused with users start conversations with disabled (deactivated) users. Previously disactivated users chats become read-only and no one can write there. Now all that chats looks like regular chats.

In my case I'm 100% sure that it have nothing to do with disabled users; the issue appears with active users.

ankar84 commented 3 years ago

In my case I'm 100% sure that it have nothing to do with disabled users; the issue appears with active users. Yes, probably you are right. Did a few test with disabled user and didn't see something suspicious.

Can you share you experience in that problem? Maybe you have Steps to reproduce?

battosai30 commented 3 years ago

Same issue here : fresh Debian machine, fresh install RC 3.16.3 and Keycloack OpenID connect It leads to "invalid user" error when you try to direct message someone, and videocall doesn't work ("call already ended"). Regards

tmartincpp commented 3 years ago

In my case I'm 100% sure that it have nothing to do with disabled users; the issue appears with active users. Yes, probably you are right. Did a few test with disabled user and didn't see something suspicious.

Can you share you experience in that problem? Maybe you have Steps to reproduce?

Please check my previous message: https://github.com/RocketChat/Rocket.Chat/issues/22256#issuecomment-874511533

Unfortunately I don't have any way to reproduce :|

battosai30 commented 3 years ago

Same with LDAP auth backend on another fresh install (not done by me furthermore). It's working well when LDAP was not connected. Clearly have an auth backend is the source of the issue.

CvH commented 3 years ago

We have the same problem but we use OAuth2 for SSO. Every user that start a pm to a use he never spoke before, the invalid user pops up and requires a refresh. That sounds like not a big deal, but if the target audience is not tech affine this is rather deal breaking because a core function is just not working. We have this problem at least since 3.14.x, it got worse with 3.15 if I remember correctly.

nickerber commented 3 years ago

I can reproduce this error....

Exception while invoking method getRoomByTypeAndName Error: Invalid room [error-invalid-room]

Steps to reproduce:

Go to the directory

Click on the Users tab

Click on a user that I have never clicked on (or had a DM with) before

In this case, it tries to load the user using the /direct/{username} URL which throws the exception and then it creates a new room and opens it for the user and redirects to the /direct/{roomId} URL

Encountering the same problem on our system.

Steps to reproduce:

Create a local user or sync a user from Active Directory
Login to this new user
Go to search and search for another user
Click on this user

Expected behavior:

A direct message channel is opened for the two users.

Actual behavior:

A grey screen appears with an error message in the top right corner: Invalid user

After refreshing the page the direct message channel is displayed correctly.

Server Setup Information:

Version of Rocket.Chat Server: 3.16.3 Operating System: Debian Buster Deployment Method: build from sources Number of Running Instances: 1 DB Replicaset Oplog: yes NodeJS Version: 12.22.1 MongoDB Version: 4.4.6

Client Setup Information

Desktop App: 3.2.3 Operating System: Windows 10 LTSC Browser: Chrome 89.0.4389.90 64 Bit

Additional Information

LDAP Backend Authentication (Active Directory) is enabled.

Relevant logs:

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

Further information

The following requests are being logged in Chrome Dev Tools:

{ROCKET_URL}/api/v1/method.call/getRoomByTypeAndName
Payload: {"message":"{\"msg\":\"method\",\"method\":\"getRoomByTypeAndName\",\"params\":[\"d\",\"username\"],\"id\":\"64\"}"}

{ROCKET_URL}/api/v1/method.call/createDirectMessage
Payload: {"message":"{\"msg\":\"method\",\"method\":\"createDirectMessage\",\"params\":[\"ern\"],\"id\":\"65\"}"}

{ROCKET_URL}/api/v1/method.call/getRoomByTypeAndName
{"message":"{\"msg\":\"method\",\"method\":\"getRoomByTypeAndName\",\"params\":[\"d\",\"BiWhEkQ54jiEq6jkQBqLwGQAydafvzzScj\"],\"id\":\"66\"}"}

Afterwards, the grey screen and the error "Invalid User" are appearing. In the adreess bar one can see the address: {ROCKET_URL}/direct/BiWhEkQ54jiEq6jkQBqLwGQAydafvzzScj After refreshing (F5) with the {ROCKET_URL}/direct/ it works and opens the correct direct message channel.

Tried to disable LDAP, but the error persists.

andys448 commented 3 years ago

Exactly the same error.

RC Log:

server.js:204 System ➔ error Exception while invoking method createDirectMessage Invalid user [error-invalid-user] 
server.js:204 Federation ➔ dns.error Error: failed [404] Not Found     
at Object.exports.makeErrorByStatus (packages/http.js:177:10)    
at Request._callback (packages/http.js:141:24)     
at Request.self.callback (/datafile/Rocket.Chat/programs/server/npm/node_modules/meteor/http/node_modules/request/request.js:185:22)    
at Request.emit (events.js:315:20)     
at Request.EventEmitter.emit (domain.js:483:12)     
at Request.<anonymous> (/datafile/Rocket.Chat/programs/server/npm/node_modules/meteor/http/node_modules/request/request.js:1161:10)     
at Request.emit (events.js:315:20)     
at Request.EventEmitter.emit (domain.js:483:12)     
at IncomingMessage.<anonymous> (/datafile/Rocket.Chat/programs/server/npm/node_modules/meteor/http/node_modules/request/request.js:1083:12)     
at Object.onceWrapper (events.js:421:28)     
at IncomingMessage.emit (events.js:327:22)     
at IncomingMessage.EventEmitter.emit (domain.js:483:12)     
at endReadableNT (_stream_readable.js:1220:12)     
at processTicksAndRejections (internal/process/task_queues.js:84:21) {   response: {     statusCode: 404,     content: 'Not Found',     headers: {       'content-length': '9',       'content-type': 'text/plain; charset=utf-8',       date: 'Thu, 05 Aug 2021 16:17:01 GMT',       etag: 'W/"9-0gXL1ngzMqISxa6S1zx3F4wtLyg"',       'x-powered-by': 'Express',       connection: 'close'     },     data: null   } }

Chrome Dev Console:

TypeError: Cannot read property 'onDestroyed' of undefined at d.TemplateInstance. <anonymous>

Uncaught (in promise) {isClientSafe: true, error: "error-invalid-user", reason: "Invalid user", details: {…}, message: "Invalid user [error-invalid-user]",…}
details: {method: "createDirectMessage"}
error: "error-invalid-user"
errorType: "Meteor.Error"
isClientSafe: true
message: "Invalid user [error-invalid-user]"
reason: "Invalid user"
stack: "Error: Invalid user [error-invalid-user] \ n at M._livedata_result
__proto__: Error
clone: ƒ ()
constructor: ƒ ()
__proto__: Object

Also after refreshing (F5) with the {ROCKET_URL}/direct/ it works and opens the correct direct message channel.

dougfabris commented 3 years ago

I can reproduce this error....

Exception while invoking method getRoomByTypeAndName Error: Invalid room [error-invalid-room]

Steps to reproduce:

Go to the directory

Click on the Users tab

Click on a user that I have never clicked on (or had a DM with) before

In this case, it tries to load the user using the /direct/{username} URL which throws the exception and then it creates a new room and opens it for the user and redirects to the /direct/{roomId} URL

Guys, the PR related and tests I ran are considering the cases when opening a single DM or multiple DM for the first time. If there's a different behavior please let me know or open another issue. Thanks a lot!

ankar84 commented 2 years ago

I can reproduce this error....

Exception while invoking method getRoomByTypeAndName Error: Invalid room [error-invalid-room]

Steps to reproduce:

Go to the directory

Click on the Users tab

Click on a user that I have never clicked on (or had a DM with) before

In this case, it tries to load the user using the /direct/{username} URL which throws the exception and then it creates a new room and opens it for the user and redirects to the /direct/{roomId} URL

That's all actually still an issue on most recent 4.4.0 But there is a room not found page in that case and normal DM after reload.

mosynaq commented 2 years ago

I have version 4.4.1 and the issue still persists. It does Not show "invalid user" error, but page refresh is required yet.

dimitrihof commented 2 years ago

Still an Error in 3.18.5. Oauth used for user login. The first time you send a message to a user it shows Invalid-User.

dougfabris commented 2 years ago

Reopening to investigate!

ankar84 commented 2 years ago

Reopening to investigate!

Hey, @dougfabris Douglas! Thank you for your interest to that issue. I think that all that logs errors can be related to tons of issues that was fixed by https://github.com/RocketChat/Rocket.Chat/pull/24955 But I'm can be wrong in that. I can tell it for sure when upgrade to 4.6.X and check logs if they have a lot of Error: Invalid room [error-invalid-room]

But to upgrade I need to wait a proxy fix https://github.com/RocketChat/Rocket.Chat/pull/25022

seregasoft commented 2 years ago

Getting crash when switching frequently between rooms or search for a user that you don't have an active direct conversation with.

Server: Docker 4.4.0 Client: WEB, Desktop 3.8.2

Use REST instead of websocket for Meteor calls disabled

DevTools errors:

TypeError: Cannot read properties of undefined (reading 'onDestroyed')
...

{isClientSafe: true, error: 'error-invalid-user', reason: 'Invalid user', details: {…}, message: 'Invalid user [error-invalid-user]', …}
details:
method: "createDirectMessage"
[[Prototype]]: Object
error: "error-invalid-user"
errorType: "Meteor.Error"
isClientSafe: true
message: "Invalid user [error-invalid-user]"
reason: "Invalid user"
stack: "Error: Invalid user [error-invalid-user] 
....

ankar84 commented 2 years ago

Server: Docker 4.4.0

Fixed in recent versions (4.5.2 I guess)

seregasoft commented 2 years ago

Server: Docker 4.4.0

Fixed in recent versions (4.5.2 I guess)

Thank you! After update server to latest 4.6.2 problem when "search for a user" is not reproduced anymore! But unfortunately "switching frequently between rooms" still gives me this error.

seregasoft commented 2 years ago

"switching frequently between rooms" still gives me this error. Fixed in 4.7.1 for me.

calebjacobson commented 2 years ago

I am experiencing a similar issue on 4.8.3, though it is intermittent

Steps to Reproduce:

send a direct message with a user (or users) for the first time (issue occurs intermittently whether using the web interface or using api/v1/chat.postMessage)
check rooms list - the direct message is added! though the error is thrown and no message appears in the room
check logs. What shows up when using the API is Error: error-not-allowed at app/authorization/server/functions/canSendMessage.ts:26:9

Expected Behavior:

add the new room without error or give a more precise explanation as to why it could not send the message

Actual Behavior

Room is added, no message is in the room, and an error is thrown (when using the web interface, "Error Not Allowed" shows up in red error bubble in the top right of the screen).

Server Setup Information:

Version of Rocket.Chat Server: 4.8.3
Operating System: Ubuntu Server 18.04.3
Deployment Method: bare metal (virtualized in a VMWare-like environment) with snap
Number of Running instances: 1
DB Replicaset Oplog: Enabled
NodeJS version: 14.18.3
MongoDB Version: 4.2.17 / wiredTiger

Client Setup Information:

Browser Version: Chrome 103.0.5060.134
Operating System: Linux Mint 20.3
LDAP is enabled

Additional context

Our rocket chat installation is being proxied through nginx for SSL termination, with rocketchat-caddy being disabled in snap.
This issue started happing several months ago and is being increasingly reported by our users. We deployed a service that utilizes a bot user to send automated messages to our users (always in individual direct messages) and have been experiencing this error occasionally the bot user attempts to send messages. All errors occur when sending a message to a user the bot user has not messaged before, however, not all messages to new users from this bot user get an error response. Rooms are created when the bot user encounters this error, but the message it attempts to send does not appear in the room.
Our users are set up and authenticated using LDAP

Relevant Logs: `sudo journalctl -r -u snap.rocketchat-server.rocketchat-server | grep error-not-allowed`

Aug 15 12:16:58 <SERVER NAME REDACTED> rocketchat-server.rocketchat-server[8232]: {"level":35,"time":"2022-08-15T12:16:58.081Z","pid":8286,"hostname":"<SERVER NAME REDACTED>","name":"API","method":"POST","url":"/api/v1/chat.postMessage","userId":"<USER ID REDACTED>","userAgent":"axios/0.27.2","length":"247","host":"<HOST REDACTED>","remoteIP":"<IP REDACTED>","err":{"type":"Error","message":"error-not-allowed","stack":"Error: error-not-allowed\n    at app/authorization/server/functions/canSendMessage.ts:26:9\n    at /snap/rocketchat-server/1523/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40\n => awaited here:\n    at Function.Promise.await (/snap/rocketchat-server/1523/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)\n    at validateRoomMessagePermissions (app/authorization/server/functions/canSendMessage.ts:70:17)\n    at processWebhookMessage (app/lib/server/functions/processWebhookMessage.js:102:3)\n    at Object.post (app/api/server/v1/chat.js:162:26)\n    at app/api/server/api.js:431:96\n    at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1257:12)\n    at Object._internalRouteActionHandler [as action] (app/api/server/api.js:431:39)\n    at Route._callEndpoint (packages/rocketchat_restivus/lib/route.coffee:150:32)\n    at packages/rocketchat_restivus/lib/route.coffee:59:33\n    at packages/simple_json-routes.js:100:9"},"status":400,"responseTime":1100,"msg":"error-not-allowed"}

ankar84 commented 1 year ago

we are on 5.3.5 now a I still get some invalid user and room errors

sumitsrv commented 1 year ago

@ankar84 and @calebjacobson have you added any temporary handling mechanism? I need to run an experiment using RocketChat and cannot wait for it to be fixed.

SudoNova commented 1 year ago

I have the same problem:

Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]: {"level":35,"time":"2023-10-10T14:27:03.168Z","pid":491506,"hostname":"fl-hq-rocketchat","name":"Meteor","method":"getRoomByTypeAndName","userId":"5S8z3zk5iu3mSkNJ7","userAgent":"Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:109.0) Gecko/20100101 Firefox/118.0","referer":"https://im.flightio.com/direct/m.shojajou","remoteIP":"127.0.0.1","instanceId":"227a6fa9-8aa5-4cd9-ac3b-4fb4dbf9e8f9"}
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]: Exception while invoking method getRoomByTypeAndName errorClass [Error]: Invalid room [error-invalid-room]
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at server/publications/room/index.ts:64:10
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:  => awaited here:
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at Function.Promise.await (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at packages/meteor.js:367:22
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at Meteor.EnvironmentVariable.EVp.withValue (packages/meteor.js:1389:31)
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at packages/ddp-server/livedata_server.js:1818:36
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at new Promise (<anonymous>)
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at Server.applyAsync (packages/ddp-server/livedata_server.js:1817:12)
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at Server.callAsync (packages/ddp-server/livedata_server.js:1743:17)
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at app/api/server/v1/misc.ts:559:33
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:  => awaited here:
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at Function.Promise.await (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at app/api/server/v1/misc.ts:559:17
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:     at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40 {
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:   isClientSafe: true,
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:   error: 'error-invalid-room',
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:   reason: 'Invalid room',
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:   details: { method: 'getRoomByTypeAndName' },
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]:   errorType: 'Meteor.Error'
Oct 10 17:57:03 fl-hq-rocketchat rocketchat[491506]: }

I use version 6.4.1

RAurelian commented 11 months ago

Same issue on v6.4.5 (snap install):

RocketChat / Rocket.Chat