[Bug]: Used memory grew by more than 50 MB when executing job OCA\DAV\BackgroundJob\RefreshWebcalJob

Markoise commented 4 months ago

⚠️ This issue respects the following points: ⚠️

[X] This is a bug, not a question or a configuration/webserver/proxy issue.
[X] This issue is not already reported on Github OR Nextcloud Community Forum (I've searched it).
[X] Nextcloud Server is up to date. See Maintenance and Release Schedule for supported versions.
[X] I agree to follow Nextcloud's Code of Conduct.

Bug description

This entry appears in the log every hour when a Google calendar is called up.

[cron] Warnung: Used memory grew by more than 50 MB when executing job OCA\DAV\BackgroundJob\RefreshWebcalJob (id: 74290, arguments: {"principaluri":"principals\/users\/markus","uri":"calendargooglecom-1"}): 119.6 MB (before: 58.6 MB) von ? von -- um 19.07.2024, 12:31:43

Steps to reproduce

Subscribe to Google Calendar

Expected behavior

No entry in the log

Installation method

Community Manual installation with Archive

Nextcloud Server version

29

Operating system

Debian/Ubuntu

PHP engine version

PHP 8.2

Web server

Nginx

Database engine version

MariaDB

Is this bug present after an update or on a fresh install?

None

Are you using the Nextcloud Server Encryption module?

Encryption is Disabled

What user-backends are you using?

[ ] Default user-backend (database)
[ ] LDAP/ Active Directory
[ ] SSO - SAML
[ ] Other

Configuration report

{
    "system": {
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "nextcloud",
            "xxx.xxx.xx",
            "192.168.178.50",
            "nextcloud.local"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "version": "29.0.4.1",
        "overwrite.cli.url": "https:\/\/xxx.xxx.xx",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "mysql.utf8mb4": true,
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "overwritehost": "xxx.xxx.xx",
        "activity_expire_days": 14,
        "allow_local_remote_servers": true,
        "auth.bruteforce.protection.enabled": true,
        "blacklisted_files": [
            ".htaccess",
            "Thumbs.db",
            "thumbs.db"
        ],
        "cron_log": true,
        "default_phone_region": "DE",
        "default_language": "de",
        "default_locale": "de",
        "default_timezone": "Europe\/Berlin",
        "enable_previews": true,
        "enabledPreviewProviders": [
            "OC\\Preview\\PNG",
            "OC\\Preview\\JPEG",
            "OC\\Preview\\GIF",
            "OC\\Preview\\BMP",
            "OC\\Preview\\XBitmap",
            "OC\\Preview\\Movie",
            "OC\\Preview\\PDF",
            "OC\\Preview\\MP3",
            "OC\\Preview\\TXT",
            "OC\\Preview\\MarkDown"
        ],
        "filesystem_check_changes": 0,
        "filelocking.enabled": "true",
        "htaccess.RewriteBase": "\/",
        "integrity.check.disabled": false,
        "knowledgebaseenabled": false,
        "log_rotate_size": "104857600",
        "logfile": "\/var\/log\/nextcloud\/nextcloud.log",
        "loglevel": 2,
        "logtimezone": "Europe\/Berlin",
        "memcache.local": "\\OC\\Memcache\\APCu",
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "overwriteprotocol": "https",
        "preview_max_x": 1024,
        "preview_max_y": 768,
        "preview_max_scale_factor": 1,
        "profile.enabled": false,
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 0,
            "password": "***REMOVED SENSITIVE VALUE***",
            "timeout": 0.5,
            "dbindex": 1
        },
        "quota_include_external_storage": false,
        "share_folder": "\/Freigaben",
        "skeletondirectory": "",
        "trashbin_retention_obligation": "auto, 90",
        "mail_smtpmode": "smtp",
        "mail_smtpsecure": "ssl",
        "mail_sendmailmode": "smtp",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "465",
        "mail_smtpauth": 1,
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
        "memories.exiftool": "\/var\/www\/nextcloud\/apps\/memories\/bin-ext\/exiftool-aarch64-glibc",
        "memories.vod.path": "\/var\/www\/nextcloud\/apps\/memories\/bin-ext\/go-vod-aarch64",
        "memories.vod.ffmpeg": "\/usr\/bin\/ffmpeg",
        "memories.vod.ffprobe": "\/usr\/bin\/ffprobe",
        "maintenance": false,
        "app_install_overwrite": [
            "news",
            "files_rightclick",
            "tasks",
            "groupfolders"
        ],
        "theme": "",
        "debug": false,
        "memories.gis_type": 1,
        "updater.release.channel": "stable",
        "versions_retention_obligation": "auto, 365",
        "simpleSignUpLink.shown": false,
        "upgrade.disable-web": true,
        "log.condition": {
            "apps": [
                "admin_audit"
            ]
        },
        "has_rebuilt_cache": true,
        "memories.db.triggers.fcu": true,
        "maintenance_window_start": 1
    }
}

List of activated Apps

Enabled:
  - activity: 2.21.1
  - admin_audit: 1.19.0
  - announcementcenter: 6.8.1
  - bookmarks: 14.2.2
  - bruteforcesettings: 2.9.0
  - calendar: 4.7.12
  - circles: 29.0.0-dev
  - cloud_federation_api: 1.12.0
  - collectives: 2.12.0
  - comments: 1.19.0
  - contacts: 6.0.0
  - contactsinteraction: 1.10.0
  - cookbook: 0.11.1
  - dashboard: 7.9.0
  - dav: 1.30.1
  - deck: 1.13.1
  - drawio: 3.0.2
  - federatedfilesharing: 1.19.0
  - federation: 1.19.0
  - files: 2.1.0
  - files_automatedtagging: 1.19.0
  - files_downloadlimit: 2.0.0
  - files_pdfviewer: 2.10.0
  - files_reminders: 1.2.0
  - files_sharing: 1.21.0
  - files_trashbin: 1.19.0
  - files_versions: 1.22.0
  - flow_notifications: 1.9.0
  - forms: 4.2.4
  - geoblocker: 0.5.14
  - gpoddersync: 3.9.0
  - gpxpod: 5.0.18
  - groupfolders: 17.0.1
  - integration_tmdb: 1.0.4
  - logreader: 2.14.0
  - lookup_server_connector: 1.17.0
  - mail: 3.7.5
  - maps: 1.4.0
  - memories: 7.3.1
  - news: 25.0.0-alpha8
  - nextcloud_announcements: 1.18.0
  - notes: 4.10.0
  - notifications: 2.17.0
  - oauth2: 1.17.0
  - password_policy: 1.19.0
  - passwords: 2024.7.20
  - photos: 2.5.0
  - previewgenerator: 5.5.0
  - privacy: 1.13.0
  - provisioning_api: 1.19.0
  - recognize: 7.0.3
  - recommendations: 2.1.0
  - related_resources: 1.4.0
  - repod: 2.3.3
  - richdocuments: 8.4.3
  - richdocumentscode_arm64: 24.4.502
  - serverinfo: 1.19.0
  - settings: 1.12.0
  - sharebymail: 1.19.0
  - spreed: 19.0.7
  - survey_client: 1.17.0
  - suspicious_login: 7.0.0
  - systemtags: 1.19.0
  - tables: 0.7.4
  - tasks: 0.16.0
  - text: 3.10.1
  - theming: 2.4.0
  - twofactor_backupcodes: 1.18.0
  - twofactor_nextcloud_notification: 3.9.0
  - twofactor_totp: 11.0.0-dev
  - updatenotification: 1.19.1
  - user_status: 1.9.0
  - viewer: 2.3.0
  - weather_status: 1.9.0
  - workflowengine: 2.11.0
Disabled:
  - encryption: 2.17.0
  - files_external: 1.21.0 (installed 1.21.0)
  - firstrunwizard: 2.18.0 (installed 2.17.0)
  - support: 1.12.0 (installed 1.11.0)
  - user_ldap: 1.20.0

Nextcloud Signing status

No errors have been found.

Nextcloud Logs

No response

Additional info

No response

ChristophWurst commented 3 months ago

@miaulalala please triage. This could be fixed by your incremental sync PR.

miaulalala commented 3 months ago

@miaulalala please triage. This could be fixed by your incremental sync PR.

Yep pretty sure that is fixed when using an incremental sync. But I'm wondering why the calendar is synced every hour. @Markoise did you manually set a sync period for every hour?

Markoise commented 3 months ago

Yep pretty sure that is fixed when using an incremental sync. But I'm wondering why the calendar is synced every hour. @Markoise did you manually set a sync period for every hour?

Yes, I did.

miaulalala commented 3 months ago

Yep pretty sure that is fixed when using an incremental sync. But I'm wondering why the calendar is synced every hour. @Markoise did you manually set a sync period for every hour?

Yes, I did.

Ok, that's fine - this will be fixed in Nextcloud 30, the job will be up to 99% faster. Are you ok to close?

Markoise commented 3 months ago

Sure. Thanks a lot. 🙂

Markoise commented 2 months ago

I also get these messages in Nextcloud 30

Used memory grew by more than 50 MB when executing job OCA\DAV\BackgroundJob\RefreshWebcalJob (id: 74290, arguments: {“principaluri”: “principals\/users\/markus”, “uri”: “calendargooglecom-1”}): 113.7 MB (before: 51.3 MB)

mayonezo commented 2 months ago

Nextcloud 30 and I get a bunch of these: {"reqId":"swEDeTs7A3dPZHgjVdW3","level":2,"time":"2024-09-23T14:12:34+02:00","remoteAddr":"","user":"--","app":"cron","method":"","url":"--","message":"Used memory grew by more than 50 MB when executing job OCA\\DAV\\BackgroundJob\\RefreshWebcalJob (id: 1275988, arguments: {\"principaluri\":\"principals\\/users\\/%user%\",\"uri\":\"calendargooglecom\"}): 83.6 MB (before: 10 MB)","userAgent":"--","version":"30.0.0.14","data":{"app":"cron"}}

mayonezo commented 2 months ago

@miaulalala Could you please reopen the issue?

miaulalala commented 1 month ago

Sure thing

Is your calendar a holiday subscription calendar or is it a regular calendar that changes a lot?

Markoise commented 1 month ago

In this case, it's my wife's Google calendar. But it doesn't change very much. Sometimes an appointment is moved, sometimes a new one is created. But that happens maybe once a day. The message in the log for this calendar appears every hour.

Subscribed school vacation, football and public holiday calendars do not cause a log entry.

miaulalala commented 1 month ago

Hm, it's interesting for sure. So, the sync interval provided by the subscription calendar is taken into account now, so the hourly message isn't really surprising if this is the provided sync interval; but I'm still suprised that the delta sync is not helping for your calendar subscription. Can you do an export of this calendar before and after the sync and use a diffing tool to check what exactly is different with those calendars? Please let me know what you find.

Markoise commented 1 month ago

Okay. I have compared two files. No changes have been made in Google Calendar. Nevertheless, the ICS files that I created with the Nextcloud app (calendar backup) are different.

In both ICS files there are DTSTAMP= entries per appointment. Here is a different value for all appointments. This seems to be the date and time of the export.

Nothing else is different. The files are 966 kb in size and contain appointments from 2013 onwards.

miaulalala commented 1 month ago

Okay. I have compared two files. No changes have been made in Google Calendar. Nevertheless, the ICS files that I created with the Nextcloud app (calendar backup) are different.

In both ICS files there are DTSTAMP= entries per appointment. Here is a different value for all appointments. This seems to be the date and time of the export.

Nothing else is different. The files are 966 kb in size and contain appointments from 2013 onwards.

Yeah I think the export generates a new DTSTAMP. We ignore the DTSTAMP when doing a sync anyway, so that shouldn't lead to a write. Lemme think some more, maybe I can find a debug strategy that will tell us more. Are you opposed to patching your instance with some debug logging?

Markoise commented 1 month ago

Yeah I think the export generates a new DTSTAMP. We ignore the DTSTAMP when doing a sync anyway, so that shouldn't lead to a write. Lemme think some more, maybe I can find a debug strategy that will tell us more. Are you opposed to patching your instance with some debug logging?

If you tell me how to do it and if it has any other effects, I can do it.

KernSani commented 1 month ago

Just to add: I have the same issue, also after upgrading to latest version of Nextcloud (30.0.1). In my case the calender is a selfhosted baikal calendar. I'm actually planning to move away from that (to nextcloud calendar), however that might still take some time, so if I can support in fixing this issue I'm happy to help.

[Edit]: Forgot to mention that my ics files are exactly the same

mayonezo commented 2 weeks ago

Issue still persists with server version 30.0.2.

nextcloud / server