Backup job runs out of memory & instance remains in maintenance mode

[mueslo]

Nextcloud Version: 23.0.0 Bacup App version: 1.0.4

PHP Version:8.0.13 Memory Limit: 512 MB Max Execution Time: 3600 Upload max size: 4 GB

Operating System FreeBSD 12.2-RELEASE-p11 amd64

I tried out the backup plugin yesterday, over 24h ago via the web interface. Ever since the backup commenced, my Nextcloud instance has been in maintenance mode. The last data in the designated backup directory was written slightly under 24h ago. I assume something failed. There are no log entries containing "OCA\Backup" since the backup started. The cron request triggering the backup job appears to be

{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 16:00:03","remoteAddr":"","user":"--","app":"cron","method":"","url":"--","message":"Run OCA\\Backup\\Cron\\Backup job with ID 43821","userAgent":"--","version":"23.0.0.10"}

The last entry of this request around the time the last file was written was

{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":3,"time":"January 07, 2022 18:20:14","remoteAddr":"","user":"--","app":"PHP","method":"","url":"--","message":"Allowed memory size of 536870912 bytes exhausted (tried to allocate 4194312 bytes) at /usr/local/www/nextcloud/apps/backup/lib/Service/ChunkService.php#477","userAgent":"--","version":"23.0.0.10"}

i.e. the request ran out of memory. I use the recommended 512MiB max PHP request size.

The whole log for the request is rather huge, so I will only attach the last 20 lines.

{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":1,"time":"January 07, 2022 18:18:38","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Flow handling done for event \\OCP\\Files::postCreate","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:18:55","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Flow activation: rules were requested for operation Automated tagging","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:18:55","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"No flow configurations is going to run Automated tagging","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:18:55","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Flow activation: rules were requested for operation Automated tagging","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:18:55","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"No flow configurations is going to run Automated tagging","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:18:55","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Flow activation: rules were requested for operation Automated tagging","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:18:55","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"No flow configurations is going to run Automated tagging","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":1,"time":"January 07, 2022 18:18:55","remoteAddr":"","user":"--","app":"no app in context","method":"","url":"--","message":"Deprecated event type for \\OCP\\Files::postCreate: Symfony\\Component\\EventDispatcher\\GenericEvent is used","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:18:55","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Flow activated by event \\OCP\\Files::postCreate","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:18:55","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Cannot handle event \\OCP\\Files::postCreate of OC\\EventDispatcher\\GenericEventWrapper against entity OCA\\WorkflowEngine\\Entity\\File and operation OCA\\Talk\\Flow\\Operation","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":1,"time":"January 07, 2022 18:18:55","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Flow handling done for event \\OCP\\Files::postCreate","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:20:14","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Flow activation: rules were requested for operation Automated tagging","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:20:14","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"No flow configurations is going to run Automated tagging","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:20:14","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Flow activation: rules were requested for operation Automated tagging","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:20:14","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"No flow configurations is going to run Automated tagging","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":1,"time":"January 07, 2022 18:20:14","remoteAddr":"","user":"--","app":"no app in context","method":"","url":"--","message":"Deprecated event type for \\OCP\\Files::postCreate: Symfony\\Component\\EventDispatcher\\GenericEvent is used","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:20:14","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Flow activated by event \\OCP\\Files::postCreate","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":0,"time":"January 07, 2022 18:20:14","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Cannot handle event \\OCP\\Files::postCreate of OC\\EventDispatcher\\GenericEventWrapper against entity OCA\\WorkflowEngine\\Entity\\File and operation OCA\\Talk\\Flow\\Operation","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":1,"time":"January 07, 2022 18:20:14","remoteAddr":"","user":"--","app":"workflowengine","method":"","url":"--","message":"Flow handling done for event \\OCP\\Files::postCreate","userAgent":"--","version":"23.0.0.10"}
{"reqId":"nokBF7Bqki4j5Gd0J1VJ","level":3,"time":"January 07, 2022 18:20:14","remoteAddr":"","user":"--","app":"PHP","method":"","url":"--","message":"Allowed memory size of 536870912 bytes exhausted (tried to allocate 4194312 bytes) at /usr/local/www/nextcloud/apps/backup/lib/Service/ChunkService.php#477","userAgent":"--","version":"23.0.0.10"}

so in addition to investigating and fixing the excessive memory usage it might be good to prevent this from locking the instance, as nothing is gained from staying in maintenance mode if the previous backup job failed.

[rutgerhendriks]

I'm running the official docker image 23.0.2 and have the same issue. I tried increasing the memory_limit by starting docker with --env "PHP_MEMORY_LIMIT=8192M" and this does change the php -i PHP_MEMORY_LIMIT value, but the backup still always fails with a message indicating the limit is 512MB. As a temporary workaround, is there anything I can do to increase the memory limit?

[danepowell]

In the interest of consolidating discussion, would you mind closing this and upvoting #308?