Wekan backup errors blocking my Cloudron backups from completing.

[jdaviescoates]

For the past 3 days this:

Unexpected response code or HTTP error when piping http://172.18.30.3:3000/databases/2077efa7-c7a1-42fd-91f2-d528e594ee54/backup?access_token=4aeb76ff9de88abec3e16d155c21d78aae5affeff6afe1a3db9914b5b2eb26fb5ccff4ff132df001030604ed866b91639862d37b3ec55c901e7752f2d52854dcb85bc7f2f55e6afded794a36e5cc91932d913d94d4dee3fa21b07afada87a2b32ef3eb26949e262118b756cc292a4f8c5051a2033ffd3e7d2dab47ed51c250b6 to /home/yellowtent/appsdata/2077efa7-c7a1-42fd-91f2-d528e594ee54/mongodbdump: status 500

Whilst backing up Wekan, has resulted in my Cloudron backup not completing.

I get the exact same thing when trying to just backup Wekan by itself too.

Help!

[jdaviescoates]

I tried restarting the app to see if that would work/ help - it didn't. Now the app can't start:

Jun 02 16:05:32 => Setting up OpenID integration
Jun 02 16:05:32 => Starting wekan
Jun 02 16:05:40 => Healtheck error: Error: connect ECONNREFUSED 172.18.19.77:3000
Jun 02 16:05:50 => Healtheck error: Error: connect ECONNREFUSED 172.18.19.77:3000
Jun 02 16:06:00 => Healtheck error: Error: connect ECONNREFUSED 172.18.19.77:3000
Jun 02 16:06:03 /app/code/bundle/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:218
Jun 02 16:06:03 throw error;
Jun 02 16:06:03 ^
Jun 02 16:06:03 2025-06-02T15:06:03Z
Jun 02 16:06:03 MongoServerSelectionError: connect ECONNREFUSED 172.18.30.3:27017
Jun 02 16:06:03 at Timeout._onTimeout (/app/code/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/sdam/topology.js:292:38)
Jun 02 16:06:03 at listOnTimeout (internal/timers.js:557:17)
Jun 02 16:06:03 at processTimers (internal/timers.js:500:7)
Jun 02 16:06:03 => awaited here:
Jun 02 16:06:03 at Function.Promise.await (/app/code/bundle/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)
Jun 02 16:06:03 at new MongoConnection (packages/mongo/mongo_driver.js:213:11)
Jun 02 16:06:03 at new MongoInternals.RemoteCollectionDriver (packages/mongo/remote_collection_driver.js:9:16)
Jun 02 16:06:03 at Object.<anonymous> (packages/mongo/remote_collection_driver.js:66:18)
Jun 02 16:06:03 at Object.defaultRemoteCollectionDriver (packages/underscore.js:784:19)
Jun 02 16:06:03 at new Collection (packages/mongo/collection.js:124:40)
Jun 02 16:06:03 at packages/idmontie_migrations.js:38:15
Jun 02 16:06:03 at packages/idmontie_migrations.js:255:4
Jun 02 16:06:03 at packages/idmontie_migrations.js:263:3
Jun 02 16:06:03 at /app/code/bundle/programs/server/boot.js:385:38
Jun 02 16:06:03 at Array.forEach (<anonymous>)
Jun 02 16:06:03 at /app/code/bundle/programs/server/boot.js:210:21
Jun 02 16:06:03 at /app/code/bundle/programs/server/boot.js:439:7
Jun 02 16:06:03 at Function.run (/app/code/bundle/programs/server/profile.js:256:14)
Jun 02 16:06:03 at /app/code/bundle/programs/server/boot.js:438:13 {
Jun 02 16:06:03 reason: TopologyDescription {
Jun 02 16:06:03 type: 'Unknown',
Jun 02 16:06:03 servers: Map(1) {
Jun 02 16:06:03 'mongodb:27017' => ServerDescription {
Jun 02 16:06:03 address: 'mongodb:27017',
Jun 02 16:06:03 type: 'Unknown',
Jun 02 16:06:03 hosts: [],
Jun 02 16:06:03 passives: [],
Jun 02 16:06:03 arbiters: [],
Jun 02 16:06:03 tags: {},
Jun 02 16:06:03 minWireVersion: 0,
Jun 02 16:06:03 maxWireVersion: 0,
Jun 02 16:06:03 roundTripTime: -1,
Jun 02 16:06:03 lastUpdateTime: 1238345383,
Jun 02 16:06:03 lastWriteDate: 0,
Jun 02 16:06:03 error: MongoNetworkError: connect ECONNREFUSED 172.18.30.3:27017
Jun 02 16:06:03 at connectionFailureError (/app/code/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connect.js:387:20)
Jun 02 16:06:03 at Socket.<anonymous> (/app/code/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connect.js:310:22)
Jun 02 16:06:03 at Object.onceWrapper (events.js:520:26)
Jun 02 16:06:03 at Socket.emit (events.js:400:28)
Jun 02 16:06:03 at emitErrorNT (internal/streams/destroy.js:106:8)
Jun 02 16:06:03 at emitErrorCloseNT (internal/streams/destroy.js:74:3)
Jun 02 16:06:03 at processTicksAndRejections (internal/process/task_queues.js:82:21) {
Jun 02 16:06:03 cause: Error: connect ECONNREFUSED 172.18.30.3:27017
Jun 02 16:06:03 at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1159:16) {
Jun 02 16:06:03 errno: -111,
Jun 02 16:06:03 code: 'ECONNREFUSED',
Jun 02 16:06:03 syscall: 'connect',
Jun 02 16:06:03 address: '172.18.30.3',
Jun 02 16:06:03 port: 27017
Jun 02 16:06:03 },
Jun 02 16:06:03 [Symbol(errorLabels)]: Set(1) { 'ResetPool' }
Jun 02 16:06:03 },
Jun 02 16:06:03 topologyVersion: null,
Jun 02 16:06:03 setName: null,
Jun 02 16:06:03 setVersion: null,
Jun 02 16:06:03 electionId: null,
Jun 02 16:06:03 logicalSessionTimeoutMinutes: null,
Jun 02 16:06:03 primary: null,
Jun 02 16:06:03 me: null,
Jun 02 16:06:03 '$clusterTime': null
Jun 02 16:06:03 }
Jun 02 16:06:03 },
Jun 02 16:06:03 stale: false,
Jun 02 16:06:03 compatible: true,
Jun 02 16:06:03 heartbeatFrequencyMS: 10000,
Jun 02 16:06:03 localThresholdMS: 15,
Jun 02 16:06:03 setName: null,
Jun 02 16:06:03 maxElectionId: null,
Jun 02 16:06:03 maxSetVersion: null,
Jun 02 16:06:03 commonWireVersion: 0,
Jun 02 16:06:03 logicalSessionTimeoutMinutes: null
Jun 02 16:06:03 },
Jun 02 16:06:03 code: undefined,
Jun 02 16:06:03 [Symbol(errorLabels)]: Set(0) {}
Jun 02 16:06:03 }

[jdaviescoates]

Ah, I think the issue was just that mongodb was stuck in a restarting state. I just hit the restart button again and it seemed to resolve itself.

[jdaviescoates]

This isn't really solved because it keep happening. Most mornings I find mongodb in a "starting" state with an orange light in services. Click restart then makes it work, but something is evidently wrong.

[nebulon]

To get more info here, first can you try to increase the memory limit for monogodb service and maybe also wekan for good measure. If this is still happening, do you have other apps using that mongodb instance on your server? You can try to temporarily stop wekan for some days if possible and see if mongodb goes into this state on its own or because of wekan queries.

[jdaviescoates]

@nebulon mongodb was already at 4.5GB but I've just upped WeKan (which I don't even really use just have a few unused legacy boards) to 1GB to see if that helps.

Although it mostly seems to happen when the complete Cloudron backup is running and it gets to WeKan.

Which other apps use mondodb?

[nebulon]

If this happening around the backup, then it is most likely that the mongodb dump for backup runs low on resources. The memory limit is only the upper limit for that service/app. It could also be that the system itself runs low on memory during that time.

Listing all apps using mongodb isn't too obvious, but you can run this sql query via SSH on your server to get the list:

mysql -uroot -ppassword box -e "select ac.appId,a.appStoreId from appAddonConfigs ac INNER JOIN apps a ON a.id=ac.appId where ac.addonId='mongodb' group by ac.appId"

[joseph]

@jdaviescoates said in Wekan backup errors blocking my Cloudron backups from completing.:

Which other apps use mondodb?

rocket.chat is only one i can think of

[jdaviescoates]

@nebulon said in Wekan backup errors blocking my Cloudron backups from completing.:

mysql -uroot -ppassword box -e "select ac.appId,a.appStoreId from appAddonConfigs ac INNER JOIN apps a ON a.id=ac.appId where ac.addonId='mongodb' group by ac.appId"

Thanks, it's only WeKan I'm using.

@joseph said in Wekan backup errors blocking my Cloudron backups from completing.:

rocket.chat is only one i can think of

Thanks, I'm not using Rocket Chat.

My backups worked last night/ this morning. But it seems everyday when I check services in the morning I have this:

Here are some logs:

https://paste.uniteddiversity.coop/?7aed63d3ef7af3ba#BiicSooyTEjs2oEY1xQoGtizyB2Lwk7C6UWgCoBZJKjP

Perhaps it could be something to do with this:

vm.max_map_count is too low
currentValue: 65530, recommendedMinimum: 1677720

[jdaviescoates]

This is still an ongoing issue. Something about Wekan's mongodb consistently creates this error which makes my backups fail:

Jun 11 01:39:13 BoxError: Unexpected response code or HTTP error when piping http://172.18.30.3:3000/databases/2077efa7-c7a1-42fd-91f2-d528e594ee54/backup?access_token=4aeb76ff9de88abec3e16d155c21d78aae5affeff6afe1a3db9914b5b2eb26fb5ccff4ff132df001030604ed866b91639862d37b3ec55c901e7752f2d52854dcb85bc7f2f55e6afded794a36e5cc91932d913d94d4dee3fa21b07afada87a2b32ef3eb26949e262118b756cc292a4f8c5051a2033ffd3e7d2dab47ed51c250b6 to /home/yellowtent/appsdata/2077efa7-c7a1-42fd-91f2-d528e594ee54/mongodbdump: status 500

A few more lines in case it's indicative:

Jun 11 01:38:43 box:services backupAddons
Jun 11 01:38:43 box:services backupAddons: backing up ["localstorage","mongodb","sendmail","oidc"]
Jun 11 01:38:43 box:services Backing up mongodb
Jun 11 01:38:43 box:shell services: grep -q avx /proc/cpuinfo
Jun 11 01:39:13 box:services pipeRequestToFile: connected with status code 500
Jun 11 01:39:13 box:backuptask fullBackup: app projects.uniteddiversity.coop backup finished. Took 30.043 seconds
Jun 11 01:39:13 box:locks write: current locks: {"backup_task":null}
Jun 11 01:39:13 box:locks release: app_2077efa7-c7a1-42fd-91f2-d528e594ee54
Jun 11 01:39:13 box:taskworker Task took 2352.713 seconds
Jun 11 01:39:13 box:tasks setCompleted - 22404: {"result":null,"error":{"stack":"BoxError: Unexpected response code or HTTP error when piping http://172.18.30.3:3000/databases/2077efa7-c7a1-42fd-91f2-d528e594ee54/backup?access_token=4aeb76ff9de88abec3e16d155c21d78aae5affeff6afe1a3db9914b5b2eb26fb5ccff4ff132df001030604ed866b91639862d37b3ec55c901e7752f2d52854dcb85bc7f2f55e6afded794a36e5cc91932d913d94d4dee3fa21b07afada87a2b32ef3eb26949e262118b756cc292a4f8c5051a2033ffd3e7d2dab47ed51c250b6 to /home/yellowtent/appsdata/2077efa7-c7a1-42fd-91f2-d528e594ee54/mongodbdump: status 500\n at ClientRequest.<anonymous> (/home/yellowtent/box/src/services.js:1353:60)\n at ClientRequest.emit (node:events:519:28)\n at HTTPParser.parserOnIncomingClient (node:_http_client:702:27)\n at HTTPParser.parserOnHeadersComplete (node:_http_common:118:17)\n at Socket.socketOnData (node:_http_client:544:22)\n at Socket.emit (node:events:519:28)\n at addChunk (node:internal/streams/readable:559:12)\n at readableAddChunkPushByteMode (node:internal/streams/readable:510:3)\n at Readable.push (node:internal/streams/readable:390:5)\n at TCP.onStreamRead (node:internal/stream_base_commons:191:23)","name":"BoxError","reason":"Addons Error","details":{},"message":"Unexpected response code or HTTP error when piping http://172.18.30.3:3000/databases/2077efa7-c7a1-42fd-91f2-d528e594ee54/backup?access_token=4aeb76ff9de88abec3e16d155c21d78aae5affeff6afe1a3db9914b5b2eb26fb5ccff4ff132df001030604ed866b91639862d37b3ec55c901e7752f2d52854dcb85bc7f2f55e6afded794a36e5cc91932d913d94d4dee3fa21b07afada87a2b32ef3eb26949e262118b756cc292a4f8c5051a2033ffd3e7d2dab47ed51c250b6 to /home/yellowtent/appsdata/2077efa7-c7a1-42fd-91f2-d528e594ee54/mongodbdump: status 500"}}
Jun 11 01:39:13 box:tasks update 22404: {"percent":100,"result":null,"error":{"stack":"BoxError: Unexpected response code or HTTP error when piping http://172.18.30.3:3000/databases/2077efa7-c7a1-42fd-91f2-d528e594ee54/backup?access_token=4aeb76ff9de88abec3e16d155c21d78aae5affeff6afe1a3db9914b5b2eb26fb5ccff4ff132df001030604ed866b91639862d37b3ec55c901e7752f2d52854dcb85bc7f2f55e6afded794a36e5cc91932d913d94d4dee3fa21b07afada87a2b32ef3eb26949e262118b756cc292a4f8c5051a2033ffd3e7d2dab47ed51c250b6 to /home/yellowtent/appsdata/2077efa7-c7a1-42fd-91f2-d528e594ee54/mongodbdump: status 500\n at ClientRequest.<anonymous> (/home/yellowtent/box/src/services.js:1353:60)\n at ClientRequest.emit (node:events:519:28)\n at HTTPParser.parserOnIncomingClient (node:_http_client:702:27)\n at HTTPParser.parserOnHeadersComplete (node:_http_common:118:17)\n at Socket.socketOnData (node:_http_client:544:22)\n at Socket.emit (node:events:519:28)\n at addChunk (node:internal/streams/readable:559:12)\n at readableAddChunkPushByteMode (node:internal/streams/readable:510:3)\n at Readable.push (node:internal/streams/readable:390:5)\n at TCP.onStreamRead (node:internal/stream_base_commons:191:23)","name":"BoxError","reason":"Addons Error","details":{},"message":"Unexpected response code or HTTP error when piping http://172.18.30.3:3000/databases/2077efa7-c7a1-42fd-91f2-d528e594ee54/backup?access_token=4aeb76ff9de88abec3e16d155c21d78aae5affeff6afe1a3db9914b5b2eb26fb5ccff4ff132df001030604ed866b91639862d37b3ec55c901e7752f2d52854dcb85bc7f2f55e6afded794a36e5cc91932d913d94d4dee3fa21b07afada87a2b32ef3eb26949e262118b756cc292a4f8c5051a2033ffd3e7d2dab47ed51c250b6 to /home/yellowtent/appsdata/2077efa7-c7a1-42fd-91f2-d528e594ee54/mongodbdump: status 500"}}
Jun 11 01:39:13 BoxError: Unexpected response code or HTTP error when piping http://172.18.30.3:3000/databases/2077efa7-c7a1-42fd-91f2-d528e594ee54/backup?access_token=4aeb76ff9de88abec3e16d155c21d78aae5affeff6afe1a3db9914b5b2eb26fb5ccff4ff132df001030604ed866b91639862d37b3ec55c901e7752f2d52854dcb85bc7f2f55e6afded794a36e5cc91932d913d94d4dee3fa21b07afada87a2b32ef3eb26949e262118b756cc292a4f8c5051a2033ffd3e7d2dab47ed51c250b6 to /home/yellowtent/appsdata/2077efa7-c7a1-42fd-91f2-d528e594ee54/mongodbdump: status 500
Jun 11 01:39:13 at ClientRequest.<anonymous> (/home/yellowtent/box/src/services.js:1353:60)
Jun 11 01:39:13 at ClientRequest.emit (node:events:519:28)
Jun 11 01:39:13 at HTTPParser.parserOnIncomingClient (node:_http_client:702:27)
Jun 11 01:39:13 at HTTPParser.parserOnHeadersComplete (node:_http_common:118:17)
Jun 11 01:39:13 at Socket.socketOnData (node:_http_client:544:22)
Jun 11 01:39:13 at Socket.emit (node:events:519:28)
Jun 11 01:39:13 at addChunk (node:internal/streams/readable:559:12)
Jun 11 01:39:13 at readableAddChunkPushByteMode (node:internal/streams/readable:510:3)
Jun 11 01:39:13 at Readable.push (node:internal/streams/readable:390:5)
Jun 11 01:39:13 at TCP.onStreamRead (node:internal/stream_base_commons:191:23)

[nebulon]

This indicates, that the mongodb instance/service could not finish creating the database dump for wekan. Maybe it ran out of memory or something else hit. Do you see any crash or more info in the actual mongodb service logs?

[jdaviescoates]

@nebulon said in Wekan backup errors blocking my Cloudron backups from completing.:

This indicates, that the mongodb instance/service could not finish creating the database dump for wekan.

It's odd because if I run a backup from the app it completes in a few seconds. There is very little data to backup.

@nebulon said in Wekan backup errors blocking my Cloudron backups from completing.:

Maybe it ran out of memory

Unlikely given it's got over 4GB and I don't think I've ever seen it hit 10% usage.

@nebulon said in Wekan backup errors blocking my Cloudron backups from completing.:

Do you see any crash or more info in the actual mongodb service logs?

I think I've looked and not seen anything obvious but I'll look again...

Did you look at the logs I shared previously?

said in Wekan backup errors blocking my Cloudron backups from completing.:

Here are some logs:

https://paste.uniteddiversity.coop/?7aed63d3ef7af3ba#BiicSooyTEjs2oEY1xQoGtizyB2Lwk7C6UWgCoBZJKjP

Perhaps it could be something to do with this:

vm.max_map_count is too low
currentValue: 65530, recommendedMinimum: 1677720