Open krenuser opened 10 months ago
Having same issue when upgrading from 6.2.10 to 6.3.0. Also tried updating to ver 6.3.10, 6.4.4 with same result.
Server Setup Information: Version of Rocket.Chat Server: latest (6.4.4) Operating System: Oracle Linux 8 Deployment Method: manual Number of Running Instances: 2 DB Replicaset Oplog: Enabled NodeJS Version: v14.21.3 MongoDB Version: 4.4.17 / wiredTiger (oplog Enabled)
Log
[2023-10-27T18:57:18.245Z] INFO 87773233-8d16-4381-a1a8-2691c8501767/MATRIX: Service 'matrix' started.
[2023-10-27T18:57:18.246Z] INFO 87773233-8d16-4381-a1a8-2691c8501767/BROKER: ✔ ServiceBroker with 2 service(s) started successfully in 597ms.
{"level":30,"time":"2023-10-27T18:57:18.767Z","pid":230485,"hostname":"rocket-app-1a","name":"CAS","msg":"Disabling CAS login service"}
### New Enterprise License
#### License validated: enterprise:*
{"level":30,"time":"2023-10-27T18:57:19.673Z","pid":230485,"hostname":"rocket-app-1a","name":"LDAP","msg":"Disabling LDAP Background Sync","jobName":"LDAP_Sync"}
{"level":30,"time":"2023-10-27T18:57:19.674Z","pid":230485,"hostname":"rocket-app-1a","name":"LDAP","msg":"Disabling LDAP Background Sync","jobName":"LDAP_Sync"}
{"level":30,"time":"2023-10-27T18:57:19.768Z","pid":230485,"hostname":"rocket-app-1a","name":"LDAP","msg":"Enabling LDAP Background Sync","jobName":"LDAP_Sync"}
Ver 6.2.12 starts fine with another issue, when loading/opening private rooms where is alot of text and RC clients/browser tab freezes and crashes. Rooms with lesser text or Direct Messages load OK
Seems that there is some problem in database and I don't know how to determine what's wrong. No additional logging provided from RC container.
Deployoing clean RC version 6.4.4 finishes successfully. Server starts and works normally. But cleaning up its database and then importing dump from an old version (with RC container disabling, starting just mongo's one and then doing mongodump from 6.2.9 mongo / mongorestore to clean database for RC 6.4.4) stucks server in the same way.
Need some help with investiating what's wrong.
Please upgrade to 6.4.6 and also set an env var OVERWRITE_SETTING_Troubleshoot_Force_Caching_Version = v1
and then, after it's fixed, you can go to admin / settings / troubleshoot and delete the value in the troubleshoot force caching version input box.
Having the same issue. Updating to 6.4.6, or really any version beyond 6.2.12 produces this same error.
@marceloschmidt, I did what you suggested, but no luck. :/
Including my log in case there's a clue I'm missing.
Nov 18 22:16:54 rc systemd[1]: Started The Rocket.Chat server.
Nov 18 22:17:05 rc rocketchat[13233]: strict mode: missing type "object" for keyword "additionalProperties" at "#" (strictTypes)
Nov 18 22:17:05 rc rocketchat[13233]: strict mode: missing type "object" for keyword "properties" at "#" (strictTypes)
Nov 18 22:17:05 rc rocketchat[13233]: strict mode: use allowUnionTypes to allow union type keyword at "#/properties/value" (strictTypes)
Nov 18 22:17:06 rc rocketchat[13233]: strict mode: "items" is 1-tuple, but minItems or maxItems/additionalItems are not specified or different at path "#/properties/matrixIds"
Nov 18 22:17:08 rc rocketchat[13233]: (node:13233) NOTE: We are formalizing our plans to enter AWS SDK for JavaScript (v2) into maintenance mode in 2023.
Nov 18 22:17:08 rc rocketchat[13233]: Please migrate your code to use AWS SDK for JavaScript (v3).
Nov 18 22:17:08 rc rocketchat[13233]: For more information, check the migration guide at https://a.co/7PzMCcy
Nov 18 22:17:08 rc rocketchat[13233]: (Use `node --trace-warnings ...` to show where the warning was created)
Nov 18 22:17:08 rc rocketchat[13233]: LocalStore: store created at
Nov 18 22:17:08 rc rocketchat[13233]: LocalStore: store created at
Nov 18 22:17:08 rc rocketchat[13233]: LocalStore: store created at
Nov 18 22:17:08 rc rocketchat[13233]: MessageType.render is deprecated. Use MessageType.message instead. livechat_webrtc_video_call
Nov 18 22:17:08 rc rocketchat[13233]: {"level":40,"time":"2023-11-19T03:17:08.813Z","pid":13233,"hostname":"rc","name":"VoIPService","msg":"Voip is not enabled. Cant start the service"}
Nov 18 22:17:10 rc rocketchat[13233]: {"level":51,"time":"2023-11-19T03:17:10.142Z","pid":13233,"hostname":"rc","name":"Migrations","msg":"Migrating from version 301 -> 303"}
Nov 18 22:17:10 rc rocketchat[13233]: {"level":51,"time":"2023-11-19T03:17:10.143Z","pid":13233,"hostname":"rc","name":"Migrations","msg":"Running up() on version 303(Add roles field and set empty for users without it)"}
Nov 18 22:17:10 rc rocketchat[13233]: {"level":51,"time":"2023-11-19T03:17:10.146Z","pid":13233,"hostname":"rc","name":"Migrations","msg":"Finished migrating."}
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.743Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/BROKER: Moleculer v0.14.29 is starting...
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.743Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/BROKER: Namespace: <not defined>
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.743Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/BROKER: Node ID: c79b99bc-42c6-40f1-afc2-01529d4484a8
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.744Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/REGISTRY: Strategy: RoundRobinStrategy
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.744Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/REGISTRY: Discoverer: LocalDiscoverer
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.745Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/BROKER: Serializer: JSONSerializer
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.752Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/BROKER: Validator: FastestValidator
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.754Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/BROKER: Registered 13 middleware(s).
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.755Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/BROKER: Transporter: TcpTransporter
Nov 18 22:17:11 rc rocketchat[13233]: {"level":51,"time":"2023-11-19T03:17:11.776Z","pid":13233,"hostname":"rc","name":"DatabaseWatcher","msg":"Using change streams"}
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.834Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/TRANSIT: Connecting to the transporter...
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.837Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/TRANSPORTER: TCP server is listening on port 42071
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.838Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/TRANSPORTER: UDP Discovery is disabled.
Nov 18 22:17:11 rc rocketchat[13233]: [2023-11-19T03:17:11.838Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/TRANSPORTER: TCP Transporter started.
Nov 18 22:17:12 rc rocketchat[13233]: [2023-11-19T03:17:12.356Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/REGISTRY: '$node' service is registered.
Nov 18 22:17:12 rc rocketchat[13233]: [2023-11-19T03:17:12.358Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/REGISTRY: 'matrix' service is registered.
Nov 18 22:17:12 rc rocketchat[13233]: [2023-11-19T03:17:12.358Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/$NODE: Service '$node' started.
Nov 18 22:17:12 rc rocketchat[13233]: [2023-11-19T03:17:12.359Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/MATRIX: Service 'matrix' started.
Nov 18 22:17:12 rc rocketchat[13233]: [2023-11-19T03:17:12.359Z] INFO c79b99bc-42c6-40f1-afc2-01529d4484a8/BROKER: ✔ ServiceBroker with 2 service(s) started successfully in 588ms.
@krenuser, I was in the same boat with the deprecation, and I found something that might help you.
I had a user in my Rocket.Chat that was causing an issue. I deleted the user, updated to 6.4.6, and this handled the problem! Server started up right away after that.
I was able to see in the service log which user was causing the issue. At first I thought it was a Mongo index, but it actually turned out to be the user.
For what it's worth, it was a bot user that was created when I first installed the server, many, many versions ago.
I'm on a VM that I can snapshot and roll back, so I was able to delete this user from the web GUI, then run the update. You may have to try deleting the user from mongosh or something if your server is no longer running.
I'm including what I found in my logs. Hope this helps!
Nov 18 22:32:32 rc rocketchat[11039]: === UnHandledPromiseRejection ===
Nov 18 22:32:32 rc rocketchat[11039]: MongoServerError: E11000 duplicate key error collection: rocketchat.users index: username_1 dup key: { username: "rocket.cat" }
Nov 18 22:32:32 rc rocketchat[11039]: at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/operations/insert.js:53:33
Nov 18 22:32:32 rc rocketchat[11039]: at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connection_pool.js:333:25
Nov 18 22:32:32 rc rocketchat[11039]: at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/sdam/server.js:210:17
Nov 18 22:32:32 rc rocketchat[11039]: at handleOperationResult (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/sdam/server.js:326:20)
Nov 18 22:32:32 rc rocketchat[11039]: at Connection.onMessage (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connection.js:242:9)
Nov 18 22:32:32 rc rocketchat[11039]: at MessageStream.<anonymous> (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connection.js:61:60)
Nov 18 22:32:32 rc rocketchat[11039]: at MessageStream.emit (events.js:400:28)
Nov 18 22:32:32 rc rocketchat[11039]: at MessageStream.emit (domain.js:475:12)
Nov 18 22:32:32 rc rocketchat[11039]: at processIncomingData (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/message_stream.js:125:16)
Nov 18 22:32:32 rc rocketchat[11039]: at MessageStream._write (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/message_stream.js:33:9)
Nov 18 22:32:32 rc rocketchat[11039]: at writeOrBuffer (internal/streams/writable.js:358:12)
Nov 18 22:32:32 rc rocketchat[11039]: at MessageStream.Writable.write (internal/streams/writable.js:303:10)
Nov 18 22:32:32 rc rocketchat[11039]: at Socket.ondata (internal/streams/readable.js:731:22)
Nov 18 22:32:32 rc rocketchat[11039]: at Socket.emit (events.js:400:28)
Nov 18 22:32:32 rc rocketchat[11039]: at Socket.emit (domain.js:475:12)
Nov 18 22:32:32 rc rocketchat[11039]: at addChunk (internal/streams/readable.js:293:12)
Nov 18 22:32:32 rc rocketchat[11039]: at readableAddChunk (internal/streams/readable.js:267:9)
Nov 18 22:32:32 rc rocketchat[11039]: at Socket.Readable.push (internal/streams/readable.js:206:10)
Nov 18 22:32:32 rc rocketchat[11039]: at TCP.onStreamRead (internal/stream_base_commons.js:188:23)
Nov 18 22:32:32 rc rocketchat[11039]: at TCP.callbackTrampoline (internal/async_hooks.js:130:17)
Nov 18 22:32:32 rc rocketchat[11039]: => awaited here:
Nov 18 22:32:32 rc rocketchat[11039]: at Function.Promise.await (/opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)
Nov 18 22:32:32 rc rocketchat[11039]: at server/startup/initialData.js:28:3
Nov 18 22:32:32 rc rocketchat[11039]: at /opt/Rocket.Chat/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40 {
Nov 18 22:32:32 rc rocketchat[11039]: index: 0,
Nov 18 22:32:32 rc rocketchat[11039]: code: 11000,
Nov 18 22:32:32 rc rocketchat[11039]: keyPattern: { username: 1 },
Nov 18 22:32:32 rc rocketchat[11039]: keyValue: { username: 'rocket.cat' },
Nov 18 22:32:32 rc rocketchat[11039]: [Symbol(errorLabels)]: Set(0) {}
Nov 18 22:32:32 rc rocketchat[11039]: }
Nov 18 22:32:32 rc rocketchat[11039]: ---------------------------------
Nov 18 22:32:32 rc rocketchat[11039]: Errors like this can cause oplog processing errors.
Nov 18 22:32:32 rc rocketchat[11039]: Setting EXIT_UNHANDLEDPROMISEREJECTION will cause the process to exit allowing your service to automatically restart the process
Nov 18 22:32:32 rc rocketchat[11039]: Future node.js versions will automatically exit the process
Nov 18 22:32:32 rc rocketchat[11039]: =================================
@postcardmaniait i was able to confirm your solution and also make the problem repeatable.
Problem is the re-created user "rocket.cat", if it was deleted and re-created through admin workspace Users>New with the same name. In mongo it now has _id value as a hash/random string, but RocketChat 6.3.0+ expects _id value of "rocket.cat" or else it wont startup.
This is not just a upgrade problem. Tried to delete and recreate the rocket.cat user in rocket 6.3.0 through Users menu. After that, rocketchat service was not able to restart. Until I deleted the rocket.cat user in mongo manually and let it create the correct rocket.cat user.
for rocket.cat user deletion in mongo shell:
use rocketchat db.users.deleteOne( { username: "rocket.cat" } )
restart rocketchat service
systemctl restart rocketchat
edit: I think the problem might be in meteor server startup initialData.js part, which handles the rocket.cat user stuff (linked if block is changed 6.2.12>6.3.0): https://github.com/RocketChat/Rocket.Chat/blob/d3c4ef1e6883af95369bce3ef683758bb4009949/apps/meteor/server/startup/initialData.js#L27
So, I've found a workaround to solve my problem.
rocketchat-1
containerexec <your_old_mongo_container_name> sh -c "mongoexport --db=rocketchat --collection=users" > ./json/users.json
(You need to get a whole list of tables somehow). This will not include indexes (which can possibly cause errors and problems). Remove "rocket.cat" user from your backup of users
table.docker exec <your_new_mongo_container_name> sh -c "mongoimport --mode=upsert --db=rocketchat --collection=users --file=/bitnami/mongodb/dumps/users.json"
(you need to place your JSON files to mongo container, to the folder "dumps" so that your backup json files to be visible from inside mongo container). I've excluded (have not imported to clean instance) these tables: migrations
(I've installed clean RC version that don't need my old migrations info), rocketchat_analytics
, rocketchat_message_reads
(don't work in community version), rocketchat_read_receipts
(either), rocketchat_server_events
, rocketchat_settings
(it needs additional cleanup), rocketchat_statistics
.Accounts_AllowedDomainsList
Accounts_AvatarCacheTime
Accounts_AvatarResize
Accounts_AvatarSize
Accounts_CustomFields
Accounts_CustomFieldsToShowInUserInfo
Accounts_Default_User_Preferences_desktopNotificationRequireInteraction
Accounts_Default_User_Preferences_hideRoles
Accounts_Default_User_Preferences_notificationsSoundVolume
Accounts_Default_User_Preferences_saveMobileBandwidth
Accounts_Default_User_Preferences_sidebarShowUnread
Accounts_Directory_DefaultView
Accounts_EmailOrUsernamePlaceholder
Accounts_EmailVerification
Accounts_Enrollment_Email
Accounts_Enrollment_Email_Subject
Accounts_PasswordPlaceholder
Accounts_PasswordReset
Accounts_RegistrationForm
Accounts_RegistrationForm_LinkReplacementText
Accounts_RegistrationForm_SecretURL
Accounts_Registration_InviteUrlType
Accounts_SearchFields
Accounts_Send_Email_When_Activating
Accounts_Send_Email_When_Deactivating
Accounts_TwoFactorAuthentication_By_Email_Auto_Opt_In
Accounts_TwoFactorAuthentication_RememberFor
Accounts_UserAddedEmail_Email
Accounts_UserAddedEmail_Subject
Analytics_features_messages
Analytics_features_rooms
Analytics_features_users
Block_Multiple_Failed_Logins_Attempts_Until_Block_by_User
Block_Multiple_Failed_Logins_Time_To_Unblock_By_User_In_Minutes
CDN_PREFIX_ALL
Cloud_Workspace_Access_Token
Cloud_Workspace_Access_Token_Expires_At
Cloud_Workspace_Client_Id
Cloud_Workspace_Client_Secret
Cloud_Workspace_Id
Cloud_Workspace_Name
Cloud_Workspace_PublicKey
Cloud_Workspace_Registration_Client_Uri
Custom_Script_Logged_In
Custom_Translations
DDP_Rate_Limit_Connection_By_Method_Requests_Allowed
DDP_Rate_Limit_Connection_Requests_Allowed
DDP_Rate_Limit_IP_Requests_Allowed
DDP_Rate_Limit_User_Requests_Allowed
Default_Custom_Timezone
Default_Referrer_Policy
Default_Timezone_For_Reporting
DirectMesssage_maxUsers
Email_Footer
Email_Header
FileUpload_Enable_json_web_token_for_files
FileUpload_FileSystemPath
FileUpload_MaxFileSize
FileUpload_MediaTypeBlackList
FileUpload_RotateImages
FileUpload_Storage_Type
First_Channel_After_Login
Iframe_Integration_receive_enable
Iframe_Integration_send_enable
Iframe_Restrict_Access
Iframe_X_Frame_Options
Invitation_Email
Jitsi_Click_To_Join_Count
Katex_Enabled
LDAP_AD_User_Search_Field
LDAP_Authentication
LDAP_Authentication_Password
LDAP_Authentication_UserDN
LDAP_Background_Sync
LDAP_Background_Sync_Interval
LDAP_Background_Sync_Keep_Existant_Users_Updated
LDAP_BaseDN
LDAP_Default_Domain
LDAP_Group_Filter_Group_Member_Format
LDAP_Host
LDAP_Login_Fallback
LDAP_Merge_Existing_Users
LDAP_Reconnect
LDAP_Sync_User_Avatar
LDAP_Sync_User_Data_Channels
LDAP_Sync_User_Data_ChannelsMap
LDAP_Sync_User_Data_Channels_Admin
LDAP_Sync_User_Data_Channels_BaseDN
LDAP_Sync_User_Data_Channels_Filter
LDAP_Sync_User_Data_Roles
LDAP_Sync_User_Data_RolesMap
LDAP_Sync_User_Data_Roles_BaseDN
LDAP_Sync_User_Data_Roles_Filter
LDAP_Timeout
LDAP_Unique_Identifier_Field
LDAP_User_Search_Field
LDAP_Username_Field
Language
Layout_Home_Body
Layout_Home_Title
Layout_Login_Terms
Livechat_External_Queue_URL
Livechat_OfflineMessageToChannel_channel_name
Livechat_Room_Count
Livechat_Visitor_navigation_as_a_message
Livechat_agent_leave_action
Livechat_display_offline_form
Livechat_enable_message_character_limit
Livechat_enable_transcript
Livechat_guest_count
Livechat_message_character_limit
Livechat_offline_form_unavailable
Livechat_offline_message
Livechat_offline_title
Livechat_request_comment_when_closing_conversation
Livechat_secret_token
Livechat_show_agent_email
Livechat_show_agent_info
Livechat_show_queue_list_link
Livechat_title
Livechat_title_color
Livechat_transcript_message
Livechat_webhookUrl
Livechat_webhook_on_agent_message
Livechat_webhook_on_chat_queued
Livechat_webhook_on_chat_taken
Livechat_webhook_on_close
Livechat_webhook_on_forward
Livechat_webhook_on_offline_msg
Livechat_webhook_on_start
Livechat_webhook_on_visitor_message
Log_View_Limit
Login_Logs_ClientIp
Message_Attachments_Thumbnails_Enabled
Message_Code_highlight
Message_DateFormat
Message_ErasureType
Message_KeepHistory
Message_MaxAllowedSize
Message_Read_Receipt_Enabled
Message_Read_Receipt_Store_Users
Message_ShowDeletedStatus
Message_TimeAndDateFormat
Message_TimeFormat
NPS_survey_enabled
Number_of_users_autocomplete_suggestions
OTR_Enable
Offline_DM_Email
Offline_Mention_Email
Organization_Email
Organization_Name
Organization_Type
SMTP_Host
SMTP_IgnoreTLS
SMTP_Password
SMTP_Pool
SMTP_Port
SMTP_Protocol
SMTP_Username
Send_visitor_navigation_history_livechat_webhook_request
Server_Type
Site_Name
Site_Url
Size
Statistics_reporting
UI_Allow_room_names_with_special_chars
UI_Click_Direct_Message
UI_Unread_Counter_Style
UI_Use_Name_Avatar
UI_Use_Real_Name
UTF8_Channel_Names_Validation
UTF8_Names_Slugify
Unread_Count
UserData_EnableDownload
UserData_FileSystemPath
UserData_FileSystemZipPath
UserData_ProcessingFrequency
VoIP_JWT_Secret
WebRTC_Enable_Channel
WebRTC_Enable_Direct
WebRTC_Enable_Private
WebRTC_Enabled
Webdav_Integration_Enabled
Website
email_style
theme-custom-css
Accounts_Default_User_Preferences_alsoSendThreadToChannel
VideoConf_Default_Provider
Assets_logo_dark
Import rocketchat_settings.json
with upsert option.
@frygor,
VERY NICE FIND! Thanks for sharing that with us!
@krenuser,
Thanks for sharing your solution!
@frygor , if you could post it a few days earlier, it could save me a bunch of time!..
Thanks! Now I see why my workaround works.
Running into the same issue. Did anyone find a better solution already? Dumping the DB and restoring is a possible workaround but not really a good option.
Description:
After upgrading RC 6.2.9 to latest version via docker-compose, server load stops on ServiceBroker message and server remains unavailable for an infinite time (doesn't start listen port 3000). The problem is that my version will deprecate on November 20 and seems that I can't do anything to solve that.
Steps to reproduce:
Expected behavior:
Server started label:
Actual behavior:
Server load hangs and last message in logs is:
And nothing happens for a very long time. MongoDB continue logging messages (remains working).
Server Setup Information:
Client Setup Information
Additional context
(none)
Relevant logs:
docker-compose.log