nextcloud / nextcloud/calendar

Subscribed calendar attempting refresh 100-200 times per day

Open
#4,966 16 comments 1 reaction 0 assignees View on GitHub

Nobody has claimed this yet.

0. to triage bug enhancement
Dominant language
JavaScript
Stars
1.2k
Forks
332
Avg merge
16h 13m
Merged PRs (30d)
137

Description

Steps to reproduce

Background:
I somehow triggered a refresh frequency limit on a subscribed calendar. I don't know how or when this first happened or if Nextcloud contributed to causing it; I only just noticed the warnings in my logs. I suspect that a caldav client, Evolution, was attempting to refresh too frequently. I have since adjusted its refresh rate. Regardless, the current situation is that the remote server is currently responding with a 503 error Your calendar software is requesting this resource too often!

Issue Details:
My Nextcloud is now attempting 100-200 refreshes of this calendar per day. It appears to try every 5 minutes for a while, then gives up for a while, then tries again every 5 minutes for another while.

According to the docs, the default value of calendarSubscriptionRefreshRate is 1x per week. I manually configured it to 1x per day on the off chance that the default setting had somehow changed to 5 minutes. No apparent change in behavior.

Repro:

  1. Subscribe to https://cantonbecker.com/astronomy-calendar/
  2. Trigger the remote server's refresh frequency limit (I don't know how this happened as explained above)
  3. Nextcloud continues to attempt refreshes every 5 minutes up to 100-200 times per day
  4. Configure calendarSubscriptionRefreshRate to P1D. Still happens.
Expected behavior

Nextcloud should not be flooding this poor server with refresh requests 100-200 times per day.

Actual behaviour

I don't know if the problem is that calendarSubscriptionRefreshRate is not being respected or if the 503 response from the remote server has triggered a different, more aggressive refresh policy until a successful connection is made. Either way, my logs show 164 attempts to refresh on Feb 5th, 204 on the 6th, and 122 so far for today the 7th.

Calendar app version

4.2.3

CalDAV-clients used

Evolution, currently refreshing 1x per day

Browser

Firefox 109

Client operating system

Arch Linux

Server operating system

Ubuntu Server 22.04.1 LTS

Web server

Apache

Database engine version

MySQL

PHP engine version

PHP 8.0

Nextcloud version

25.0.3 installed from Snap

Updated from an older installed version or fresh install

Updated from an older version

List of activated apps
Enabled:
  - activity: 2.17.0
  - bruteforcesettings: 2.5.0
  - calendar: 4.2.3
  - circles: 25.0.0
  - cloud_federation_api: 1.8.0
  - comments: 1.15.0
  - contacts: 5.1.0
  - contactsinteraction: 1.6.0
  - dashboard: 7.5.0
  - dav: 1.24.0
  - deck: 1.8.3
  - encryption: 2.13.0
  - federatedfilesharing: 1.15.0
  - federation: 1.15.0
  - files: 1.20.1
  - files_pdfviewer: 2.6.0
  - files_rightclick: 1.4.0
  - files_sharing: 1.17.0
  - files_trashbin: 1.15.0
  - files_versions: 1.18.0
  - firstrunwizard: 2.14.0
  - logreader: 2.10.0
  - lookup_server_connector: 1.13.0
  - mail: 2.2.2
  - maps: 0.2.4
  - memories: 4.10.3
  - music: 1.8.1
  - nextcloud_announcements: 1.14.0
  - notifications: 2.13.1
  - oauth2: 1.13.0
  - password_policy: 1.15.0
  - photos: 2.0.1
  - privacy: 1.9.0
  - provisioning_api: 1.15.0
  - recommendations: 1.4.0
  - related_resources: 1.0.3
  - serverinfo: 1.15.0
  - settings: 1.7.0
  - sharebymail: 1.15.0
  - spreed: 15.0.3
  - support: 1.8.0
  - systemtags: 1.15.0
  - tasks: 0.14.5
  - text: 3.6.0
  - theming: 2.0.1
  - timetracker: 0.0.77
  - twofactor_backupcodes: 1.14.0
  - twofactor_totp: 7.0.0
  - user_status: 1.5.0
  - viewer: 1.9.0
  - weather_status: 1.5.0
  - workflowengine: 2.7.0
Disabled:
  - admin_audit
  - backup: 1.2.0
  - event_update_notification: 2.0.0
  - files_external
  - files_texteditor: 2.15.0
  - notes: 4.6.0
  - richdocuments: 7.1.0
  - richdocumentscode_arm64: 22.5.802
  - social: 0.4.2
  - survey_client: 1.11.0
  - suspicious_login
  - user_ldap
Nextcloud configuration
{
    "system": {
        "apps_paths": [
            {
                "path": "\/snap\/nextcloud\/current\/htdocs\/apps",
                "url": "\/apps",
                "writable": false
            },
            {
                "path": "\/var\/snap\/nextcloud\/current\/nextcloud\/extra-apps",
                "url": "\/extra-apps",
                "writable": true
            }
        ],
        "supportedDatabases": [
            "mysql"
        ],
        "memcache.locking": "\\OC\\Memcache\\Redis",
        "memcache.local": "\\OC\\Memcache\\Redis",
        "redis": {
            "host": "***REMOVED SENSITIVE VALUE***",
            "port": 0
        },
        "log_type": "file",
        "logfile": "\/var\/snap\/nextcloud\/current\/logs\/nextcloud.log",
        "logfilemode": 416,
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "***REMOVED SENSITIVE VALUE***",
            "***REMOVED SENSITIVE VALUE***",
            "***REMOVED SENSITIVE VALUE***"
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "version": "25.0.3.2",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "mysql.utf8mb4": true,
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "twofactor_enforced": "true",
        "twofactor_enforced_groups": [],
        "twofactor_enforced_excluded_groups": [],
        "mail_smtpmode": "smtp",
        "mail_smtpsecure": "tls",
        "mail_sendmailmode": "smtp",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "587",
        "mail_smtpauthtype": "LOGIN",
        "mail_smtpauth": 1,
        "mail_smtpname": "***REMOVED SENSITIVE VALUE***",
        "mail_smtppassword": "***REMOVED SENSITIVE VALUE***",
        "maintenance": false,
        "loglevel": 0,
        "overwriteprotocol": "https",
        "app_install_overwrite": [
            "files_texteditor"
        ],
        "overwrite.cli.url": "***REMOVED SENSITIVE VALUE***",
        "default_phone_region": "US",
        "allow_local_remote_servers": true,
        "memories.exiftool": "\/var\/snap\/nextcloud\/33060\/nextcloud\/extra-apps\/memories\/exiftool-bin\/exiftool-aarch64-glibc"
    }
}
Web server error log

No response

Log file
{"reqId":"lhG7cXe6HcmCHkpY7o4F","level":2,"time":"2023-02-07T13:49:56+00:00","remoteAddr":"","user":"--","app":"dav","method":"","url":"--","message":"Subscription 1 could not be refreshed due to a network error","userAgent":"--","version":"25.0.3.2","exception":{"Exception":"GuzzleHttp\\Exception\\ServerException","Message":"Server error: `GET https://cantonbecker.com/astronomy-calendar-files/astrocal.ics` resulted in a `503 Service Temporarily Unavailable` response:\n<h1>503 Service Temporarily Unavailable</h1><p>Your calendar software is requesting this resource too often!\n\t\t\t<br />\n\t (truncated...)\n","Code":503,"Trace":[{"file":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/guzzle/src/Middleware.php","line":69,"function":"create","class":"GuzzleHttp\\Exception\\RequestException","type":"::"},{"file":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/promises/src/Promise.php","line":204,"function":"GuzzleHttp\\{closure}","class":"GuzzleHttp\\Middleware","type":"::","args":["*** sensitive parameters replaced ***"]},{"file":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/promises/src/Promise.php","line":153,"function":"callHandler","class":"GuzzleHttp\\Promise\\Promise","type":"::"},{"file":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/promises/src/TaskQueue.php","line":48,"function":"GuzzleHttp\\Promise\\{closure}","class":"GuzzleHttp\\Promise\\Promise","type":"::","args":["*** sensitive parameters replaced ***"]},{"file":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/promises/src/Promise.php","line":248,"function":"run","class":"GuzzleHttp\\Promise\\TaskQueue","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/promises/src/Promise.php","line":224,"function":"invokeWaitFn","class":"GuzzleHttp\\Promise\\Promise","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/promises/src/Promise.php","line":269,"function":"waitIfPending","class":"GuzzleHttp\\Promise\\Promise","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/promises/src/Promise.php","line":226,"function":"invokeWaitList","class":"GuzzleHttp\\Promise\\Promise","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/promises/src/Promise.php","line":62,"function":"waitIfPending","class":"GuzzleHttp\\Promise\\Promise","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/guzzle/src/Client.php","line":187,"function":"wait","class":"GuzzleHttp\\Promise\\Promise","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/lib/private/Http/Client/Client.php","line":218,"function":"request","class":"GuzzleHttp\\Client","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/apps/dav/lib/CalDAV/WebcalCaching/RefreshWebcalService.php","line":217,"function":"get","class":"OC\\Http\\Client\\Client","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/apps/dav/lib/CalDAV/WebcalCaching/RefreshWebcalService.php","line":89,"function":"queryWebcalFeed","class":"OCA\\DAV\\CalDAV\\WebcalCaching\\RefreshWebcalService","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/apps/dav/lib/BackgroundJob/RefreshWebcalJob.php","line":115,"function":"refreshSubscription","class":"OCA\\DAV\\CalDAV\\WebcalCaching\\RefreshWebcalService","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/lib/public/BackgroundJob/Job.php","line":78,"function":"run","class":"OCA\\DAV\\BackgroundJob\\RefreshWebcalJob","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/lib/public/BackgroundJob/Job.php","line":64,"function":"start","class":"OCP\\BackgroundJob\\Job","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/apps/dav/lib/BackgroundJob/RefreshWebcalJob.php","line":108,"function":"execute","class":"OCP\\BackgroundJob\\Job","type":"->"},{"file":"/snap/nextcloud/33503/htdocs/cron.php","line":152,"function":"execute","class":"OCA\\DAV\\BackgroundJob\\RefreshWebcalJob","type":"->"}],"File":"/snap/nextcloud/33503/htdocs/3rdparty/guzzlehttp/guzzle/src/Exception/RequestException.php","Line":113,"message":"Subscription 1 could not be refreshed due to a network error","exception":[],"CustomMessage":"Subscription 1 could not be refreshed due to a network error"},"id":"63e25e48a9f8d"}
Browser log

No response

Additional info

No response

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with apps/dav/lib/CalDAV/WebcalCaching/RefreshWebcalService.php, especially queryWebcalFeed and refreshSubscription, then follow apps/dav/lib/BackgroundJob/RefreshWebcalJob.php from cron.php. Reproduce a subscribed calendar returning 503 and verify that calendarSubscriptionRefreshRate is respected rather than causing repeated five-minute requests.

Written by the indexing model from the issue text.

Assessment

Tech stack
php
Domain
backend
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Active
Clarity
Mostly clear
Newbie friendliness
55/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.