search

nextcloud / mail

💌 Mail app for Nextcloud
https://apps.nextcloud.com/apps/mail
GNU Affero General Public License v3.0
851 stars 263 forks source link

Mailbox sync huge memory consumption #10179

Open stafra opened 2 months ago

stafra commented 2 months ago

Steps to reproduce

  1. Install fresh nextcloud from snap (Ubuntu 24.04.1 LTS)
  2. Add nextcloud user with "big" mailbox (19 GB) with INBOX size 13 GB, configure it's mailbox usint imap, wait for sync
  3. The mailbox sync process dies on low memory even if there is 284 GB memory (incl. swap) configured and available

Expected behavior

The sync process should take resonable amount of memory.

Actual behavior

The sync process dies on low memory even if a huge swap used:

root@nextcloud:~# /snap/bin/nextcloud.occ mail:account:sync -vvv 3
[debug] Skipping mailbox sync for 37
[debug] Skipping mailbox sync for 45
[debug] Skipping mailbox sync for 41
[debug] Skipping mailbox sync for 8
[debug] Skipping mailbox sync for 40
[debug] Syncing 9
[debug] Locking mailbox 9 for new messages sync
[debug] Locking mailbox 9 for changed messages sync
[debug] Locking mailbox 9 for vanished messages sync
[debug] Running partial sync for 9
[debug] partial sync 3:INBOX - get all known UIDs took 0s. 45/73MB memory used
[debug] partial sync 3:INBOX - get new messages via Horde took 187s. 2411/3093MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 457s. 12818/12841MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 549s. 23179/23202MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 471s. 33575/33597MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 464s. 43970/43993MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 472s. 54345/54368MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 654s. 64680/64703MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 465s. 75076/75099MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 481s. 85473/85496MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 718s. 95794/95817MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 483s. 106190/106213MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 482s. 116584/116607MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 487s. 126982/127005MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 440s. 131194/131289MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 499s. 141662/141685MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 498s. 152062/152085MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 486s. 162460/162483MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 705s. 172791/172814MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 489s. 183187/183210MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 486s. 193582/193605MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 706s. 203935/203958MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 503s. 214332/214355MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 500s. 224727/224750MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 795s. 235054/235077MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 505s. 245448/245470MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 498s. 255842/255864MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 787s. 266178/266201MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 508s. 276577/276600MB memory used
[debug] partial sync 3:INBOX - classified a chunk of new messages took 506s. 286972/286995MB memory used
root@nextcloud:~#
root@nextcloud:~# tail -f /var/snap/nextcloud/current/logs/php_errors.log
[14-Sep-2024 01:36:51 UTC] PHP Fatal error:  Allowed memory size of 304942678016 bytes exhausted (tried to allocate 4194312 bytes) in /var/snap/nextcloud/44304/nextcloud/extra-apps/mail/lib/Cache/Cache.php on line 184
[14-Sep-2024 01:37:29 UTC] PHP Fatal error:  Allowed memory size of 304942678016 bytes exhausted (tried to allocate 258048 bytes) in /snap/nextcloud/44304/htdocs/lib/private/Memcache/Redis.php on line 94
[14-Sep-2024 15:55:01 UTC] PHP Fatal error:  Allowed memory size of 304942678016 bytes exhausted (tried to allocate 4194312 bytes) in /var/snap/nextcloud/44304/nextcloud/extra-apps/mail/lib/Cache/Cache.php on line 184
[14-Sep-2024 15:55:38 UTC] PHP Fatal error:  Allowed memory size of 304942678016 bytes exhausted (tried to allocate 2097152 bytes) in /var/snap/nextcloud/44304/nextcloud/extra-apps/mail/lib/Cache/Cache.php on line 144

Memory limit is set realy high (I just tried a ridiculously high limit):

root@nextcloud:~# free
               total        used        free      shared  buff/cache   available
Mem:         8131952     1826820      271928       45424     6392816     6305132
Swap:      298844148       51600   298792548

root@nextcloud:~# snap set nextcloud php.memory-limit=284G

After repetated run the mailbox seems to be synced - but I am not sure if it is fully synced and if I can trust it in the future. I'll need to do fresh resync in the future (we will migrate our mail domain to a private solution I'm testing) and I don't want to do this workaround with a huge swap.

Mail app version

3.7.8

Mailserver or service

Dovecot 2.3.16 (on premise)

Operating system

Ubuntu 24.04.1 LTS

PHP engine version

PHP 8.2

Web server

Apache (supported)

Database

MySQL

Additional info

No response

ChristophWurst commented 1 month ago

Hi @stafra! Thanks a lot for the well structured report and the debugging you've already done.

We have seen some similar out of memory errors in production recently. Unfortunately they are often tricky to diagnose because the PHP process ends abruptly with no stack trace.

Would you be willing to gather more debug information with our guidance? We can run the same CLI sync with xdebug trace and hopefully see where memory is not freed.

stafra commented 1 month ago

I will be happy to help with debugging. :-)

ChristophWurst commented 1 month ago
  1. Install the xdebug extension for PHP
  2. /usr/bin/php -d zend_extension=xdebug -d xdebug.mode=trace -d xdebug.start_with_request=yes -d xdebug.output_dir=/tmp occ mail:account:sync -vvv 3 (might need adjustment for snap. basically you run the occ php script with some options for the php interpreter)
  3. Find the trace file as /tmp/trace.*.xt.gz

It should be somewhat human readable. As an alternative, you could also try the machine readable one with the helper script: https://stackoverflow.com/questions/36266376/how-do-i-use-xdebug-to-find-a-php-memory-leak

stafra commented 1 month ago

My Nextcloud system is running in "snap", which does not allow direct execution of the php binary. Running xdebug from the host system is not possible, "occ" is not a php script, but a link to the snap:

root@nextcloud:~# ls -l /snap/bin/nextcloud.occ
lrwxrwxrwx 1 root root root 13 Sep 18 09:59 /snap/bin/nextcloud.occ -> /usr/bin/snap

The snap installation doesn't include the xdebug extension and it's not possible to install it (I don't know how to). I feel that my system is not debugging friendly and that I will not be able to deliver the required outputs. Sorry for that.

ChristophWurst commented 1 month ago

No worries