Hubot-slack: Hubot slack adapter disconnecting - Rate limited , will retry 3 seconds
Description
i'm running hubot v3.3.2 and hubot-slack v4.8.1
i tested my configuration in a Slack sandbox workspace and everything looked good but when switching to our production workspace i'm constantly getting:
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
followed by e.g. warn: Reconnecting, on attempt 1
Have found some threads about this but i'm not using robot.brain so e.g. https://github.com/slackapi/hubot-slack/blob/main/src/bot.coffee#L56-L58 doesn't seem to apply to this.
Please advice.
What type of issue is this? (place an x in one of the [ ])
- [x] bug
- [ ] enhancement (feature request)
- [ ] question
- [ ] documentation related
- [x] testing related
- [ ] discussion
Requirements (place an x in each of the [ ])
- [x] I've read and understood the Contributing guidelines and have done my best effort to follow them.
- [x] I've read and agree to the Code of Conduct.
- [x] I've searched for any related issues and avoided creating a duplicate issue.
Bug Report
Filling out the following details about bugs will help us solve your issue sooner.
Reproducible in:
hubot-slack version:4.8.1
node version: v10.23.1
OS version(s):CentOS Linux release 7.9.2009
Steps to reproduce:
1.just start the hubot using "HUBOT_SLACK_TOKEN=xoxb-XYZ ./bin/hubot --adapter slack
2.
3.
Expected result:
the bot to connect to the slack workspace.
Actual result:
the bot is sometimes connected, sometimes it is not, sometimes after it successfully connects it's being disconnected.
Attachments:
Logs, screenshots, screencast, sample project, funny gif, etc.
question
magander3
All 8 comments
hmm, I am still not sure what is happening in your app. Having HUBOT_LOG_LEVEL=debug to enable debug-level logging may be helpful for learning more about the situation. Can you try this out?
HUBOT_SLACK_TOKEN=xoxb-XYZ HUBOT_LOG_LEVEL=debug ./bin/hubot --adapter slack
seratch
on 29 Jan 2021
thanks for getting back @seratch - i ran it in debug mode for some time and here is the result. Can it be caused by the high number of users, 20K ?
HUBOT_LOG_LEVEL=debug HUBOT_SLACK_TOKEN=xoxb-XYZ ./bin/hubot --adapter slack
audited 159 packages in 0.916s
2 packages are looking for funding
run `npm fund` for details
found 0 vulnerabilities
[Fri Jan 29 2021 15:55:57 GMT+0000 (Coordinated Universal Time)] DEBUG Loading adapter slack
[Fri Jan 29 2021 15:55:58 GMT+0000 (Coordinated Universal Time)] INFO hubot-slack adapter v4.8.1
warn: SlackDataStore is deprecated and will be removed in the next major version. See project documentation for a migration guide.
warn: SlackDataStore is deprecated and will be removed in the next major version. See project documentation for a migration guide.
[Fri Jan 29 2021 15:55:58 GMT+0000 (Coordinated Universal Time)] DEBUG RtmClient initialized with options: undefined
[Fri Jan 29 2021 15:55:58 GMT+0000 (Coordinated Universal Time)] DEBUG RtmClient#start() with options: {}
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG SlackBot#authenticated() Found self in RTM start data
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] INFO Logged in as @prod01bot in workspace XYZ
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] INFO Connected to Slack RTM
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Loading scripts from /home/centos/prod01/scripts
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/scripts/prod01.coffee
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] INFO /home/centos/prod01/scripts/prod01.coffee is using deprecated documentation syntax
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/scripts/welcome.coffee
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] INFO /home/centos/prod01/scripts/welcome.coffee is using deprecated documentation syntax
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Loading scripts from /home/centos/prod01/src/scripts
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Loading external-scripts from npm packages
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/node_modules/hubot-diagnostics/src/diagnostics.js
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/node_modules/hubot-help/src/help.js
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] INFO hubot-redis-brain: Using default redis on localhost:6379
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/node_modules/hubot-redis-brain/src/redis-brain.js
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/node_modules/hubot-rules/src/rules.js
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/node_modules/hubot-google-images/src/google-images.coffee
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/node_modules/hubot-google-translate/src/google-translate.coffee
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/node_modules/hubot-pugme/src/pugme.coffee
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/node_modules/hubot-maps/src/maps.coffee
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG Parsing help for /home/centos/prod01/node_modules/hubot-shipit/src/shipit.coffee
[Fri Jan 29 2021 15:56:17 GMT+0000 (Coordinated Universal Time)] DEBUG hubot-redis-brain: Successfully connected to Redis
[Fri Jan 29 2021 15:56:18 GMT+0000 (Coordinated Universal Time)] INFO hubot-redis-brain: Data for hubot brain retrieved from Redis
[Fri Jan 29 2021 15:56:19 GMT+0000 (Coordinated Universal Time)] DEBUG SlackBot#presenceSub() Subscribing to presence for 20000 users
warn: Reconnecting, on attempt 1
[Fri Jan 29 2021 15:56:43 GMT+0000 (Coordinated Universal Time)] DEBUG SlackBot#authenticated() Found self in RTM start data
[Fri Jan 29 2021 15:56:43 GMT+0000 (Coordinated Universal Time)] INFO Logged in as @prod01bot in workspace prod01
[Fri Jan 29 2021 15:56:44 GMT+0000 (Coordinated Universal Time)] INFO Connected to Slack RTM
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
[Fri Jan 29 2021 15:57:44 GMT+0000 (Coordinated Universal Time)] DEBUG Received file_shared message from: undefined, file_id: C01L74V9UD1
[Fri Jan 29 2021 15:57:44 GMT+0000 (Coordinated Universal Time)] DEBUG No listeners executed; falling back to catch-all
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
[Fri Jan 29 2021 16:01:37 GMT+0000 (Coordinated Universal Time)] DEBUG Received file_shared message from: undefined, file_id: C01L74V9UD1
[Fri Jan 29 2021 16:01:37 GMT+0000 (Coordinated Universal Time)] DEBUG No listeners executed; falling back to catch-all
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
[Fri Jan 29 2021 16:02:11 GMT+0000 (Coordinated Universal Time)] DEBUG Received text message in channel: C01KKPX0Q5S, from: U07TEKJHX (human)
info: Rate limited, will retry 3 seconds
[Fri Jan 29 2021 16:02:15 GMT+0000 (Coordinated Universal Time)] DEBUG Message 'hypervisors supported' matched regex //(hypervisors.*supported)|(hypervisor.*supported)|(hypervisors.*support)|(hypervisor.*support)|(supported.*hypervisors)|(supported.*hypervisor)|(support.*hypervisors)|(support.*hypervisor)|(supported.*feature)|(compatibility.*matrix)|(versions.*supported)|(version.*support)|(version.*supported)|(version.*supported)|(supported.*versions)|(support.*version)|(supported.*version)|(supported.*version)/i/; listener.options = { id: null }
[Fri Jan 29 2021 16:02:15 GMT+0000 (Coordinated Universal Time)] DEBUG Executing listener callback for Message 'hypervisors supported'
[Fri Jan 29 2021 16:02:15 GMT+0000 (Coordinated Universal Time)] DEBUG SlackClient#send() room: D10YYAB0Q6T, message: Consult the latest <https://xyz.com/page/downloads|prod01 Release Note documentation> for supported DB engine and operating systems.
Thank you
prod01 Team
info: Rate limited, will retry 3 seconds
[Fri Jan 29 2021 16:02:20 GMT+0000 (Coordinated Universal Time)] DEBUG SlackClient#fetchBotUser() Calling bots.info API for bot_id: C01L74V9UD1
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
[Fri Jan 29 2021 16:08:10 GMT+0000 (Coordinated Universal Time)] DEBUG Received file_shared message from: undefined, file_id: F01BGTRAEFTLR4
[Fri Jan 29 2021 16:08:10 GMT+0000 (Coordinated Universal Time)] DEBUG No listeners executed; falling back to catch-all
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
[Fri Jan 29 2021 16:12:39 GMT+0000 (Coordinated Universal Time)] DEBUG Received file_shared message from: undefined, file_id: F01BGTRAEFTLR4
[Fri Jan 29 2021 16:12:39 GMT+0000 (Coordinated Universal Time)] DEBUG No listeners executed; falling back to catch-all
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
[Fri Jan 29 2021 16:15:16 GMT+0000 (Coordinated Universal Time)] DEBUG Received file_shared message from: undefined, file_id: F01BGTRAEFTLR4
[Fri Jan 29 2021 16:15:16 GMT+0000 (Coordinated Universal Time)] DEBUG No listeners executed; falling back to catch-all
[Fri Jan 29 2021 16:15:47 GMT+0000 (Coordinated Universal Time)] DEBUG Received file_shared message from: undefined, file_id: F01M20GF6Q0
[Fri Jan 29 2021 16:15:47 GMT+0000 (Coordinated Universal Time)] DEBUG No listeners executed; falling back to catch-all
[Fri Jan 29 2021 16:18:18 GMT+0000 (Coordinated Universal Time)] DEBUG Received file_shared message from: undefined, file_id: F01BGTRAEFTLR4
[Fri Jan 29 2021 16:18:18 GMT+0000 (Coordinated Universal Time)] DEBUG No listeners executed; falling back to catch-all
@magander3 Thanks for sharing this!
Can it be caused by the high number of users, 20K ?
Good point. As pagination with the default settings 100 users per an API request, I'm sure your app should be trying to perform 200 API calls!
The options for this is to use DISABLE_USER_SYNC=false or set API_PAGE_SIZE=1000 (1K is the upper limit for this).
https://github.com/slackapi/hubot-slack/blob/v4.9.0/slack.coffee#L7-L8
seratch
on 29 Jan 2021
Ok great @seratch - however don't understand how disableUserSync set to false will prevent users from being synced.
I have tried the following changes to slack.coffee
Test 1:
apiPageSize:1000
Test 2:
disableUserSync:false
apiPageSize:1000
Test 3:
disableUserSync:true
Both during Test1 and Test2 i immediately got:
info: Rate limited, will retry 3 seconds
info: Rate limited, will retry 3 seconds
With Test3 configuration i haven't got the same message for 30 minutes. Usually appears immediately.
Will keep the bot running now and will update the thread.
Thanks
magander3
on 30 Jan 2021
👍1
DISABLE_USER_SYNC=false
oops, of course, this needs to be true as you did.
With Test3 configuration i haven't got the same message for 30 minutes. Usually appears immediately.
Will keep the bot running now and will update the thread.
Awesome 馃憤
seratch
on 31 Jan 2021
@seratch Not a single message after 24h so i would say it works like a charm.
What is the drawback of not having users synced e.g slower responses in DM ?
thanks
magander3
on 31 Jan 2021
@magander3
What is the drawback of not having users synced e.g slower responses in DM ?
Your understanding is correct. For the first access of user data, hubot-slack performs users.info API call for given user_id. Once hubot-slack successfully receives the user's data, it adds the API call result to cache results and the cached data will be used for the following requests. Therefore, the performance impact should be quite limited.
If you don't mind, can we close this issue now?
seratch
on 1 Feb 2021
ok sounds good.
Sure - let's close this one.
Tnx
magander3
on 1 Feb 2021
👍1
Was this page helpful?
0 / 5 - 0 ratings
Related issues
nfons
路
6Comments
jabbink
路
4Comments
EasyAsABC123
路
13Comments
hparadiz
路
11Comments
ojacques
路
9Comments