Description
Hi,
its more than a year we launched rocketchat-server and using it, as data grows on database (now it is nearly 60GB) in some conditions or some periods of day, users could not send message properly. the wirte the message but even the user hit the enter, message stock in gray-out mode and user must wait for about 1 or two minutes. in some cases, user must reload the application and write the message again. although user refresh the rocketchat-app it can not refreshed and application took long time to load the history.
I checkd the DB. in the mentioned problem, we face high IO on db.
Also, I check DB commands which run on db and count them as bellow:
on a secondary node:
702228 rocketchat.rocketchat_message
324635 rocketchat.$cmd
186477 rocketchat.rocketchat_message_read_receipt
148297 rocketchat.rocketchat_notification_queue
123513 rocketchat.rocketchat_subscription
32141 rocketchat.usersSessions
30451 rocketchat.instances
27433 rocketchat.users
18676 rocketchat.rocketchat_sessions
13065 rocketchat.rocketchat__trash
6838 rocketchat.rocketchat_room
5046 rocketchat.meteor_oauth_pendingCredentials
4802 rocketchat.meteor_oauth_pendingRequestTokens
3108 rocketchat.rocketchat_cron_history
1442 rocketchat.rocketchat_uploads
575 rocketchat._raix_push_app_tokens
185 rocketchat.rocketchat_avatars
161 rocketchat.rocketchat_settings
158 rocketchat.rocketchat_oembed_cache
109 rocketchat.ufsTokens
45 rocketchat.meteor_accounts_loginServiceConfiguration
39 rocketchat.rocketchat_roles
35 rocketchat.rocketchat_permissions
28 rocketchat.rocketchat_integrations
27 rocketchat.rocketchat_raw_imports
19 rocketchat.rocketchat_statistics
19 rocketchat.rocketchat_export_operations
17 rocketchat.rocketchat_custom_emoji
16 rocketchat.rocketchat_custom_sounds
14 rocketchat.rocketchat_custom_user_status
13 rocketchat.rocketchat_avatars.files
10 rocketchat.rocketchat_banner
8 rocketchat.rocketchat_avatars.chunks
7 rocketchat.rocketchat_apps_persistence
6 rocketchat.rocketchat_apps_logs
5 rocketchat.migrations
4 rocketchat.rocketchat_team_member
3 rocketchat.rocketchat_uploads.chunks
2 rocketchat.view_livechat_queue_status
2 rocketchat.rocketchat_team
2 rocketchat.rocketchat_livechat_agent_activity
1 rocketchat.rocketchat_reports
1 rocketchat.rocketchat_omnichannel_queue
1 rocketchat.rocketchat_nps_vote
1 rocketchat.rocketchat_nps
1 rocketchat.rocketchat_livechat_visitor
1 rocketchat.rocketchat_livechat_business_hours
1 rocketchat.rocketchat_invites
1 rocketchat.rocketchat_import_data
1 rocketchat.rocketchat_import
1 rocketchat.rocketchat_email_message_history
1 rocketchat.rocketchat_email_inbox
1 rocketchat.rocketchat_banner_dismiss
1 rocketchat.rocketchat_apps_scheduler
1 rocketchat.omnichannel_scheduler
1 rocketchat.omnichannel_auto_close_on_hold_scheduler
1 rocketchat
and primary node:
97314 rocketchat.$cmd
77429 rocketchat.rocketchat_message
58285 rocketchat.rocketchat_message_read_receipt
42701 rocketchat.rocketchat_notification_queue
41081 rocketchat.rocketchat_subscription
9036 rocketchat.usersSessions
8374 rocketchat.instances
8086 rocketchat.users
6313 rocketchat.rocketchat_sessions
5274 rocketchat.rocketchat__trash
1724 rocketchat.rocketchat_room
1395 rocketchat.meteor_oauth_pendingCredentials
1339 rocketchat.meteor_oauth_pendingRequestTokens
1013 rocketchat.rocketchat_uploads
847 rocketchat.rocketchat_cron_history
138 rocketchat._raix_push_app_tokens
51 rocketchat.rocketchat_settings
46 rocketchat.rocketchat_oembed_cache
27 rocketchat.ufsTokens
25 rocketchat.rocketchat_avatars
17 rocketchat.meteor_accounts_loginServiceConfiguration
8 rocketchat.rocketchat_integrations
6 rocketchat.rocketchat_raw_imports
5 rocketchat.rocketchat_statistics
4 rocketchat.rocketchat_permissions
4 rocketchat.rocketchat_avatars.chunks
4 rocketchat.rocketchat_apps_logs
3 rocketchat.rocketchat_invites
2 rocketchat.view_livechat_queue_status
2 rocketchat.rocketchat_roles
2 rocketchat.rocketchat_custom_user_status
2 rocketchat.rocketchat_apps
1 rocketchat.rocketchat_livechat_business_hours
1 rocketchat.rocketchat_import
1 rocketchat.rocketchat_custom_sounds
1 rocketchat.rocketchat_custom_emoji
1 rocketchat.rocketchat_avatars.files
I appreciate any help.
Server Setup Information
- Version of Rocket.Chat Server:
- Operating System: 3.16.3
- Number of Running Instances: 2 app server and 3 DB
- DB Replicaset Oplog: yes
- NodeJS Version: v12.18.4
- MongoDB Version: 4.0.18 / mmapv1 (oplog Enabled)
- Proxy: haproxy
- Firewalls involved: no
Some additonal logs from mongoDB
2021-08-23T15:26:57.310+0430 I COMMAND [conn102] command rocketchat.rocketchat_notification_queue command: findAndModify { findAndModify: "rocketchat_notification_queue", query: { $and: [ { $or: [ { sending: { $exists: false } }, { sending: { $lte: new Date(1629715917146) } } ] }, { $or: [ { schedule: { $exists: false } }, { schedule: { $lte: new Date(1629716217146) } } ] }, { error: { $exists: false } } ] }, sort: { ts: 1 }, new: false, remove: false, upsert: false, update: { $set: { sending: new Date(1629716217146) } }, lsid: { id: UUID("40732ffa-a5f0-4821-ae9b-43cc3975261e") }, $clusterTime: { clusterTime: Timestamp(1629716216, 65), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "rocketchat" } planSummary: IXSCAN { ts: 1 } keysExamined:8 docsExamined:8 nMatched:0 nModified:0 numYields:0 reslen:217 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 1 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 162221 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_msg 162ms
2021-08-23T15:26:55.117+0430 I COMMAND [conn102] command rocketchat.rocketchat_notification_queue command: findAndModify { findAndModify: "rocketchat_notification_queue", query: { $and: [ { $or: [ { sending: { $exists: false } }, { sending: { $lte: new Date(1629715915007) } } ] }, { $or: [ { schedule: { $exists: false } }, { schedule: { $lte: new Date(1629716215007) } } ] }, { error: { $exists: false } } ] }, sort: { ts: 1 }, new: false, remove: false, upsert: false, update: { $set: { sending: new Date(1629716215007) } }, lsid: { id: UUID("40732ffa-a5f0-4821-ae9b-43cc3975261e") }, $clusterTime: { clusterTime: Timestamp(1629716214, 69), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "rocketchat" } planSummary: IXSCAN { ts: 1 } keysExamined:8 docsExamined:8 nMatched:0 nModified:0 numYields:0 reslen:217 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 1 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 105189 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_msg 105ms
2021-08-23T15:26:52.987+0430 I COMMAND [conn103] command rocketchat.rocketchat_notification_queue command: findAndModify { findAndModify: "rocketchat_notification_queue", query: { $and: [ { $or: [ { sending: { $exists: false } }, { sending: { $lte: new Date(1629715912672) } } ] }, { $or: [ { schedule: { $exists: false } }, { schedule: { $lte: new Date(1629716212672) } } ] }, { error: { $exists: false } } ] }, sort: { ts: 1 }, new: false, remove: false, upsert: false, update: { $set: { sending: new Date(1629716212672) } }, lsid: { id: UUID("6d3ef2ef-61ca-424f-8ae3-78eac97de4c9") }, $clusterTime: { clusterTime: Timestamp(1629716212, 66), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "rocketchat" } planSummary: IXSCAN { ts: 1 } keysExamined:8 docsExamined:8 nMatched:0 nModified:0 numYields:0 reslen:217 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 1 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 313639 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_msg 314ms
2021-08-23T15:26:50.672+0430 I COMMAND [conn101] command rocketchat.rocketchat_notification_queue command: findAndModify { findAndModify: "rocketchat_notification_queue", query: { $and: [ { $or: [ { sending: { $exists: false } }, { sending: { $lte: new Date(1629715910048) } } ] }, { $or: [ { schedule: { $exists: false } }, { schedule: { $lte: new Date(1629716210048) } } ] }, { error: { $exists: false } } ] }, sort: { ts: 1 }, new: false, remove: false, upsert: false, update: { $set: { sending: new Date(1629716210048) } }, lsid: { id: UUID("62cdd23b-4e4f-41bd-9783-5a5fc779bfd0") }, $clusterTime: { clusterTime: Timestamp(1629716209, 67), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "rocketchat" } planSummary: IXSCAN { ts: 1 } keysExamined:8 docsExamined:8 nMatched:0 nModified:0 numYields:0 reslen:217 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 1 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 621430 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_msg 621ms
2021-08-23T15:26:45.960+0430 I COMMAND [conn102] command rocketchat.rocketchat_notification_queue command: findAndModify { findAndModify: "rocketchat_notification_queue", query: { $and: [ { $or: [ { sending: { $exists: false } }, { sending: { $lte: new Date(1629715905190) } } ] }, { $or: [ { schedule: { $exists: false } }, { schedule: { $lte: new Date(1629716205190) } } ] }, { error: { $exists: false } } ] }, sort: { ts: 1 }, new: false, remove: false, upsert: false, update: { $set: { sending: new Date(1629716205190) } }, lsid: { id: UUID("40732ffa-a5f0-4821-ae9b-43cc3975261e") }, $clusterTime: { clusterTime: Timestamp(1629716204, 138), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "rocketchat" } planSummary: IXSCAN { ts: 1 } keysExamined:8 docsExamined:8 nMatched:0 nModified:0 numYields:0 reslen:217 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 1 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 768880 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_msg 769ms
2021-08-23T15:26:43.158+0430 I COMMAND [conn104] command rocketchat.rocketchat_notification_queue command: findAndModify { findAndModify: "rocketchat_notification_queue", query: { $and: [ { $or: [ { sending: { $exists: false } }, { sending: { $lte: new Date(1629715903023) } } ] }, { $or: [ { schedule: { $exists: false } }, { schedule: { $lte: new Date(1629716203023) } } ] }, { error: { $exists: false } } ] }, sort: { ts: 1 }, new: false, remove: false, upsert: false, update: { $set: { sending: new Date(1629716203023) } }, lsid: { id: UUID("62cdd23b-4e4f-41bd-9783-5a5fc779bfd0") }, $clusterTime: { clusterTime: Timestamp(1629716202, 8), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "rocketchat" } planSummary: IXSCAN { ts: 1 } keysExamined:8 docsExamined:8 nMatched:0 nModified:0 numYields:0 reslen:217 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 1 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 132952 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_msg 133ms
2021-08-23T15:26:38.975+0430 I COMMAND [conn104] command rocketchat.rocketchat_notification_queue command: findAndModify { findAndModify: "rocketchat_notification_queue", query: { $and: [ { $or: [ { sending: { $exists: false } }, { sending: { $lte: new Date(1629715898832) } } ] }, { $or: [ { schedule: { $exists: false } }, { schedule: { $lte: new Date(1629716198832) } } ] }, { error: { $exists: false } } ] }, sort: { ts: 1 }, new: false, remove: false, upsert: false, update: { $set: { sending: new Date(1629716198832) } }, lsid: { id: UUID("62cdd23b-4e4f-41bd-9783-5a5fc779bfd0") }, $clusterTime: { clusterTime: Timestamp(1629716197, 65), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "rocketchat" } planSummary: IXSCAN { ts: 1 } keysExamined:8 docsExamined:8 nMatched:0 nModified:0 numYields:0 reslen:217 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 2 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 140306 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 }, acquireWaitCount: { W: 1 }, timeAcquiringMicros: { W: 1761 } } } protocol:op_msg 142ms
2021-08-23T15:26:38.974+0430 I COMMAND [conn112] command rocketchat.rocketchat_notification_queue command: findAndModify { findAndModify: "rocketchat_notification_queue", query: { $and: [ { $or: [ { sending: { $exists: false } }, { sending: { $lte: new Date(1629715898856) } } ] }, { $or: [ { schedule: { $exists: false } }, { schedule: { $lte: new Date(1629716198856) } } ] }, { error: { $exists: false } } ] }, sort: { ts: 1 }, new: false, remove: false, upsert: false, update: { $set: { sending: new Date(1629716198856) } }, lsid: { id: UUID("c7c3413c-dc95-485c-9727-e98fdc3944e4") }, $clusterTime: { clusterTime: Timestamp(1629716197, 65), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "rocketchat" } planSummary: IXSCAN { ts: 1 } keysExamined:8 docsExamined:8 nMatched:0 nModified:0 numYields:0 reslen:217 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 1 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 116718 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_msg 117ms
2021-08-23T15:26:36.830+0430 I COMMAND [conn114] command rocketchat.rocketchat_notification_queue command: findAndModify { findAndModify: "rocketchat_notification_queue", query: { $and: [ { $or: [ { sending: { $exists: false } }, { sending: { $lte: new Date(1629715896351) } } ] }, { $or: [ { schedule: { $exists: false } }, { schedule: { $lte: new Date(1629716196351) } } ] }, { error: { $exists: false } } ] }, sort: { ts: 1 }, new: false, remove: false, upsert: false, update: { $set: { sending: new Date(1629716196351) } }, lsid: { id: UUID("26137f0a-b2b7-4412-939a-b21bfc607fd9") }, $clusterTime: { clusterTime: Timestamp(1629716194, 7), signature: { hash: BinData(0, 0000000000000000000000000000000000000000), keyId: 0 } }, $db: "rocketchat" } planSummary: IXSCAN { ts: 1 } keysExamined:8 docsExamined:8 nMatched:0 nModified:0 numYields:0 reslen:217 locks:{ Global: { acquireCount: { r: 1, w: 1 } }, MMAPV1Journal: { acquireCount: { w: 1 }, acquireWaitCount: { w: 1 }, timeAcquiringMicros: { w: 477661 } }, Database: { acquireCount: { w: 1 } }, Collection: { acquireCount: { W: 1 } } } protocol:op_msg 478ms
