Hubot message no longer visible since 0.67.0

[giray]

Description:

Since the upgrade to 0.67.0 hubot instances have gone silent. All bots are online, they receive messages, process and send a response. However, no message is displayed in any channels or DMs

Steps to reproduce:

1. upgrade to 0.67.0
2. type in private channel where hubot lives hubot help

Expected behavior:

hubot should respond with help

Actual behavior:

No response from bot

Server Setup Information:

• Version of Rocket.Chat Server: 0.67.0
• hubot@2.19.0
• hubot-rocketchat@1.0.12
• Operating System: docker rocketchat/rocket.chat latest
• Deployment Method: Docker
• Number of Running Instances: 1
• DB Replicaset Oplog:
• NodeJS Version:
• MongoDB Version: mongo:3.0

Additional context

Other incoming and outgoing integration for fine. 3 bots that have been working well for more then a year have all of a sudden stopped. Further investigation shows this only is applicable to private channels. Public channels do not have this issue

Relevant logs:

[hobbez1]

Our hubot has similair issue. Direct messages to the bot does not work, but when running "bot help" in a public group, the bot does respond.

From the logs, it seems as if the room lookup has issues:
Failed DM:
hubot_1 | [Fri Jul 27 2018 07:49:40 GMT+0000 (UTC)] INFO Message receive callback id T9gw2dgqafGQHQbzj ts Fri Jul 27 2018 07:49:39 GMT+0000 (UTC)
hubot_1 | [Fri Jul 27 2018 07:49:40 GMT+0000 (UTC)] INFO [Incoming] ****: bot help
hubot_1 | [Fri Jul 27 2018 07:49:40 GMT+0000 (UTC)] INFO Message sent to hubot brain.
hubot_1 | [Fri Jul 27 2018 07:49:40 GMT+0000 (UTC)] INFO Sending Message To Room: [redacted string of chars]
hubot_1 | [Fri Jul 27 2018 07:49:40 GMT+0000 (UTC)] INFO Looking up Room ID for: [redacted string of chars]

Successful group message:
hubot_1 | [Fri Jul 27 2018 07:51:18 GMT+0000 (UTC)] INFO Message received with ID id
hubot_1 | [Fri Jul 27 2018 07:51:18 GMT+0000 (UTC)] INFO Message receive callback id n6NitFhQgfovCkopY ts Fri Jul 27 2018 07:51:18 GMT+0000 (UTC)
hubot_1 | [Fri Jul 27 2018 07:51:18 GMT+0000 (UTC)] INFO [Incoming] ****: bot help
hubot_1 | [Fri Jul 27 2018 07:51:18 GMT+0000 (UTC)] INFO Looking up Room Name for: F8CJyynGWt2eAMduT
hubot_1 | [Fri Jul 27 2018 07:51:18 GMT+0000 (UTC)] INFO setting roomName: testbot
hubot_1 | [Fri Jul 27 2018 07:51:18 GMT+0000 (UTC)] INFO Message sent to hubot brain.
hubot_1 | [Fri Jul 27 2018 07:51:18 GMT+0000 (UTC)] INFO Sending Message To Room: testbot
hubot_1 | [Fri Jul 27 2018 07:51:18 GMT+0000 (UTC)] INFO Looking up Room ID for: testbot

[ramrami]

@hobbez1 are you talking about Internal Hubot ? if it's the case you should enable it for DM

[hobbez1]

@ramrami
No its not internal hubot, it it external running, and yes, it is set for DM
RESPOND_TO_DM=true

[giray]

So I have been trying to see what happens with tcpdump ... and whenever the bot tries to respond it sends

{"msg":"updated","methods":["84"]}

and gets back

{
	"msg": "result",
	"id": "84",
	"error": {
		"isClientSafe": true,
		"error": "error-not-allowed",
		"reason": "Not allowed",
		"details": {
			"method": "getRoomIdByNameOrId"
		},
		"message": "Not allowed [error-not-allowed]",
		"errorType": "Meteor.Error"
	}
}

[giray]

So it looks like this problem exists only for private channels. The bots work fine on public channels

[giray]

This seems indeed to be due to Remove cache layer and internal calculated property room.usernames (#10749) so the solutions if for the hubot-rocketchat adapter not to use the cache layer anymore

See RocketChat/hubot-rocketchat#295

[timkinnane]

@giray You're totally right about where the issue comes from, but the cache in Hubot is something entirely different to what's referred to in those changes. This isn't an issue to be resolved in hubot.

Wish I'd seen this earlier. Been chasing it back all the way through the SDK. Have a fix to submit now though anyway...

In summary:

• [BREAK] Remove cache layer and internal calculated property room.usernames #10749 removed usernames from the room object, so getRoomIdByNameOrId couldn't check for the user in the room anymore.
• Instead of finding another solution, the logic was simply removed and would only work then for public channels.
• I'm submitting a PR that uses a different auth method, that re-instates the check for user in room.

Related issues:

• No permission policy available to access getRoomIdByNameOrId() when not a member #11131
• getRoomIdByNameOrId not working for private rooms Rocket.Chat.js.SDK#21
• Can't use Hubot initiative send message in the private group, getRoomIdByNameOrId not allowed. hubot-rocketchat#295

PR incoming.

HELP!

It would really help to have someone submit a regression test to Rocket.Chat core, to protect these methods from changing in ways that wipe out a bunch of peoples bots.

It would also be great if someone can go over the other methods in that commit and any other methods that do implement custom permission checking logic. They should all be using RocketChat.authz.canAccessRoom to keep things DRY and prevent such instances of point failures.

@rodrigok Any comment?

[stevenmcastano]

So is this something we need to grab a new version of the hubot adaptor for? Or do we need to wait for this to be merged into the main RockChat repo so we can recompile the entire chat application?

[timkinnane]

@stevenmcastano Need to wait for the merge. Currently nothing can be done in the SDK, bot or adapter. getRoomIdByNameOrId was changed in core and won't return ID for private channels.

[timkinnane]

@stevenmcastano I also noticed the method is marked as deprecated. So I don't know what's going on there.

It might be that eventually the adapters need a new way of doing it, e.g. through the Rest API using the SDK, but that's a pretty big change and would effect a lot of legacy Hubots.