rocket.chat does not want to start anymore

[luckow]

mh. yesterday everything worked as usual.
Today rocket.chat does not start anymore. This is the part from the logfile:

Apr 06 11:20:32 | SERVER RUNNING |
Apr 06 11:20:32 +------------------------------------------------------+
Apr 06 11:20:32 | |
Apr 06 11:20:32 | Rocket.Chat Version: 6.1.1 |
Apr 06 11:20:32 | NodeJS Version: 14.21.2 - x64 |
Apr 06 11:20:32 | MongoDB Version: 4.4.19 |
Apr 06 11:20:32 | MongoDB Engine: unknown |
Apr 06 11:20:32 | Platform: linux |
Apr 06 11:20:32 | Process Port: 3000 |
Apr 06 11:20:32 | Site URL: https://chat.example.org |
Apr 06 11:20:32 | ReplicaSet OpLog: Enabled |
Apr 06 11:20:32 | Commit Hash: b6919400b9 |
Apr 06 11:20:32 | Commit Branch: HEAD |
Apr 06 11:20:32 | |
Apr 06 11:20:32 +------------------------------------------------------+
Apr 06 11:20:38 box:settings initCache: pre-load settings
Apr 06 11:20:38 box:taskworker Starting task 13927. Logs are at /home/yellowtent/platformdata/logs/12345/ID/apptask.log
Apr 06 11:20:38 box:apptask run: startTask installationState: pending_restart runState: running
Apr 06 11:20:38 box:tasks update 13927: {"percent":10,"message":"Starting app services"}
Apr 06 11:20:38 box:tasks update 13927: {"percent":20,"message":"Restarting container"}
Apr 06 11:20:38 [2023-04-06T09:20:38.627Z] INFO fb1d7087-a7aa-413b-be27-bb69927ad9a2/$NODE: Service '$node' stopped.
Apr 06 11:20:38 [2023-04-06T09:20:38.628Z] INFO fb1d7087-a7aa-413b-be27-bb69927ad9a2/MATRIX: Service 'matrix' stopped.
Apr 06 11:20:38 [2023-04-06T09:20:38.631Z] INFO fb1d7087-a7aa-413b-be27-bb69927ad9a2/BROKER: ServiceBroker is stopped. Good bye.
Apr 06 11:20:39 => Creating runtime directories
Apr 06 11:20:39 => Setting up LDAP integration
Apr 06 11:20:39 box:tasks update 13927: {"percent":80,"message":"Configuring reverse proxy"}
Apr 06 11:20:39 box:reverseproxy providerMatchesSync: subject=CN = chat.example.org domain=chat.example.org issuer=C = US, O = Let's Encrypt, CN = R3 wildcard=false/false prod=true/true issuerMismatch=false wildcardMismatch=false match=true
Apr 06 11:20:39 box:reverseproxy expiryDate: subject=CN = chat.example.org notBefore=Feb 8 12:10:08 2023 GMT notAfter=May 9 12:10:07 2023 GMT daysLeft=33.117676851851854
Apr 06 11:20:39 box:reverseproxy needsRenewal: false. force: false
Apr 06 11:20:39 box:reverseproxy ensureCertificate: chat.example.org acme cert exists and is up to date
Apr 06 11:20:39 box:reverseproxy writeAppLocationNginxConfig: writing config for "chat.example.org" to /home/yellowtent/platformdata/nginx/applications/12345/ID/chat.example.org.conf with options {"sourceDir":"/home/yellowtent/box","vhost":"chat.example.org","hasIPv6":true,"ip":"172.18.16.8","port":3000,"endpoint":"app","redirectTo":null,"certFilePath":"/home/yellowtent/platformdata/nginx/cert/chat.example.org.cert","keyFilePath":"/home/yellowtent/platformdata/nginx/cert/chat.example.org.key","robotsTxtQuoted":"\"\\\"# Disable search engine indexing\\\\n\\\\nUser-agent: *\\\\nDisallow: /\\\"\"","cspQuoted":null,"hideHeaders":[],"proxyAuth":{"id":"12345/ID","location":"/"},"upstreamUri":"","ocsp":true,"hstsPreload":false}
Apr 06 11:20:39 box:shell reload spawn: /usr/bin/sudo -S /home/yellowtent/box/src/scripts/restartservice.sh nginx
Apr 06 11:20:39 box:tasks update 13927: {"percent":100,"message":"Done"}
Apr 06 11:20:39 box:taskworker Task took 1.488 seconds
Apr 06 11:20:39 box:tasks setCompleted - 13927: {"result":null,"error":null}
Apr 06 11:20:39 box:tasks update 13927: {"percent":100,"result":null,"error":null}
Apr 06 11:20:42 => Existing installation detected
Apr 06 11:20:44 ]0;mongosh mongodb://<credentials>@mongodb:12345/ID?directConnection=trueGJ G{
Apr 06 11:20:44 acknowledged: true,
Apr 06 11:20:44 insertedId: null,
Apr 06 11:20:44 matchedCount: 1,
Apr 06 11:20:44 modifiedCount: 0,
Apr 06 11:20:44 upsertedCount: 0
Apr 06 11:20:44 }

Restoring the last backup does not work either. This is the error message:

Addons Error: Unexpected response code or HTTP error when piping /home/yellowtent/appsdata/1091d04d-c585-42ab-9de8-c2a72bb8c4f4/mongodbdump to http://172.18.30.3:3000/databases/DATABASE-ID/restore?access_token=TOKEN: status 500 complete false

[luckow]

In my case, waiting for many minutes solved my problem. After restoring the current backup and restoring the database it took 25 times

Apr 06 12:23:55 => Existing installation detected
Apr 06 12:23:57 ]0;mongosh mongodb://<credentials>@mongodb:1234/LONG-ID?directConnection=trueGJ G{
Apr 06 12:23:57 acknowledged: true,
Apr 06 12:23:57 insertedId: null,
Apr 06 12:23:57 matchedCount: 1,
Apr 06 12:23:57 modifiedCount: 0,
Apr 06 12:23:57 upsertedCount: 0
Apr 06 12:23:57 }

to start rocket.chat.
In the meantime I recognized a lot of ServerStatus was very slow messages in the mongo log file.

[nebulon]

Do you see anything in the mongodb service logs when it fails piping the backup dump?

[luckow]

@nebulon I have never looked at the Mongo logs before. Is there a hint to look out for?
The current log has a size of about 5 MB

[luckow]

In my case, waiting for many minutes solved my problem. After restoring the current backup and restoring the database it took 25 times

Apr 06 12:23:55 => Existing installation detected
Apr 06 12:23:57 ]0;mongosh mongodb://<credentials>@mongodb:1234/LONG-ID?directConnection=trueGJ G{
Apr 06 12:23:57 acknowledged: true,
Apr 06 12:23:57 insertedId: null,
Apr 06 12:23:57 matchedCount: 1,
Apr 06 12:23:57 modifiedCount: 0,
Apr 06 12:23:57 upsertedCount: 0
Apr 06 12:23:57 }

to start rocket.chat.
In the meantime I recognized a lot of ServerStatus was very slow messages in the mongo log file.

[jdaviescoates]

@luckow said in rocket.chat does not want to start anymore:

it took 25 times

Presumably 25 minutes?