Skip to content

Subscribed calendar attempting refresh 100-200 times per day #4966

@inthreedee

Description

@inthreedee

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

Metadata

Metadata

Assignees

No one assigned

    Labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions