Server: Connection in Evolution to calendar via CalDAV fails (OPTION requests return 404)

Created on 24 Apr 2020 · 16Comments · Source: nextcloud/server

Steps to reproduce

(same as in #13382)

Set up any calendar via CalDAV in Evolution: Enter your server URL and user name, click on "Find Calendars", all your calendars will be listed
Select any calendar to set up
You will receive a message: "Failed to connect calendar: CalDAV [Calendar name]"

Expected behaviour

I should be able to interact with the calendar I just selected,
via Evolution on my laptop/desktop (Ubuntu Linux) as well as via DavX5 on my smartphone (Android).

Actual behaviour

CALDAV interaction on my Android device works fine,
but Evolution sends an OPTION request to the DAV endpoint and fails with a 404 :

"OPTIONS /remote.php/dav/calendars/[Username]/[Calendar name]/ HTTP/1.1" 404 1536 "-" "Evolution/3.28.5"

This is the UI error message in Evolution:
error_message

Everything worked fine on 18.0.3 until I upgraded to 18.0.4 a few hours ago.

What might help:
I found a fix for the same problem for an older NC version in this PR: #13354
Comparing method

handleAnonymousOptions(RequestInterface $request, ResponseInterface $response)

in file

apps/dav/lib/Connector/Sabre/AnonymousOptionsPlugin.php

between current 18.0.4.2 and an old backup of 18.0.2.2,
I saw that function

isRequestInRoot($path)

does not appear in

handleAnonymousOptions(RequestInterface $request, ResponseInterface $response)

anymore.
This had been added in the related PR as a fix though.

Additionally, I found the message

"File with name /calendars could not be located"

in the logs, exactly when the issue appeared.
Full log entry is on bottom under "Nextcloud log".

Please let me know if you need more information.
Thank you!

Server configuration

Operating system:
Ubuntu 18.04.4 LTS 64bit, 4.15.0-96-generic

Web server:
Apache/2.4.29 (Ubuntu)

Database:
10.1.44-MariaDB-0ubuntu0.18.04.1 Ubuntu 18.04

PHP version:
7.2.24-0ubuntu0.18.04.4

Nextcloud version: (see Nextcloud admin page)
18.0.4.2

Updated from an older Nextcloud/ownCloud or fresh install:
Updated from 18.0.3.0

Where did you install Nextcloud from:
Update via Updater App

Signing status:
No errors have been found.

List of activated apps:

Enabled:
  - admin_audit: 1.8.0
  - bruteforcesettings: 1.6.0
  - calendar: 2.0.3
  - carnet: 0.20.0
  - cloud_federation_api: 1.1.0
  - contacts: 3.3.0
  - dav: 1.14.0
  - drawio: 0.9.5
  - federatedfilesharing: 1.8.0
  - files: 1.13.1
  - files_antivirus: 2.3.0
  - files_pdfviewer: 1.7.0
  - files_rightclick: 0.15.2
  - files_sharing: 1.10.1
  - files_trashbin: 1.8.0
  - files_versions: 1.11.0
  - files_videoplayer: 1.7.0
  - logreader: 2.3.0
  - lookup_server_connector: 1.6.0
  - nextcloud_announcements: 1.7.0
  - notifications: 2.6.0
  - oauth2: 1.6.0
  - password_policy: 1.8.0
  - photos: 1.0.0
  - privacy: 1.2.0
  - provisioning_api: 1.8.0
  - serverinfo: 1.8.0
  - settings: 1.0.0
  - tasks: 0.12.1
  - twofactor_backupcodes: 1.7.0
  - twofactor_totp: 4.1.3
  - updatenotification: 1.8.0
  - viewer: 1.2.0
  - workflowengine: 2.0.0

Disabled:
  - accessibility
  - activity
  - comments
  - encryption
  - federation
  - files_external
  - firstrunwizard
  - recommendations
  - sharebymail
  - support
  - survey_client
  - systemtags
  - text
  - theming
  - user_ldap

Nextcloud configuration:

{
    "system": {
        "instanceid": "***REMOVED SENSITIVE VALUE***",
        "passwordsalt": "***REMOVED SENSITIVE VALUE***",
        "secret": "***REMOVED SENSITIVE VALUE***",
        "trusted_domains": [
            "my.domain.de",
        ],
        "datadirectory": "***REMOVED SENSITIVE VALUE***",
        "dbtype": "mysql",
        "version": "18.0.4.2",
        "overwrite.cli.url": "http:\/\/[local IP address]\/",
        "dbname": "***REMOVED SENSITIVE VALUE***",
        "dbhost": "***REMOVED SENSITIVE VALUE***",
        "dbport": "",
        "dbtableprefix": "oc_",
        "mysql.utf8mb4": true,
        "dbuser": "***REMOVED SENSITIVE VALUE***",
        "dbpassword": "***REMOVED SENSITIVE VALUE***",
        "installed": true,
        "memcache.local": "\\OC\\Memcache\\APCu",
        "enable_previews": false,
        "mail_smtpmode": "smtp",
        "mail_sendmailmode": "smtp",
        "mail_from_address": "***REMOVED SENSITIVE VALUE***",
        "mail_smtphost": "***REMOVED SENSITIVE VALUE***",
        "mail_smtpport": "25",
        "maintenance": false,
        "data-fingerprint": "[data FP]",
        "mail_domain": "***REMOVED SENSITIVE VALUE***",
        "theme": "",
        "loglevel": 2,
        "has_rebuilt_cache": true,
        "twofactor_enforced": "true",
        "twofactor_enforced_groups": [
            "admin"
        ],
        "twofactor_enforced_excluded_groups": [],
        "updater.secret": "***REMOVED SENSITIVE VALUE***"
    }
}

Are you using external storage, if yes which one: local/smb/sftp/...
No

Are you using encryption: yes/no
No

Are you using an external user-backend, if yes which one: LDAP/ActiveDirectory/Webdav/...
No

Client configuration

Browser/LDAV Client:
Evolution 3.28.5-0ubuntu0.18.04.2

Operating system:
Ubuntu 18.04.4 LTS 64bit, 5.3.0-46-generic

Logs

Web server access log (relevant area)

[myAddress] - - [24/Apr/2020:02:40:30 +0200] "OPTIONS /remote.php/dav/calendars/[myUser]/[myCalendar]/ HTTP/1.1" 404 1534 "-" "Evolution/3.28.5"                                                                         
[myAddress] - - [24/Apr/2020:02:40:31 +0200] "OPTIONS /remote.php/dav/calendars/[myUser]/[myCalendar]/ HTTP/1.1" 404 1536 "-" "Evolution/3.28.5"                                                                         
[myAddress] - - [24/Apr/2020:02:40:32 +0200] "OPTIONS /remote.php/dav/calendars/[myUser]/[myCalendar]/ HTTP/1.1" 404 1530 "-" "Evolution/3.28.5"                                                                         
[myAddress] - - [24/Apr/2020:02:40:32 +0200] "OPTIONS /remote.php/dav/calendars/[myUser]/[myCalendar]/ HTTP/1.1" 404 1536 "-" "Evolution/3.28.5"                                                                         
[myAddress] - [myUser] [24/Apr/2020:02:41:22 +0200] "PROPFIND /remote.php/dav/files/[myUser]/ HTTP/1.1" 207 4257 "-" "Mozilla/5.0 (Linux) mirall/2.6.4git (Nextcloud)"                                               
[myPhonesAddress] - - [24/Apr/2020:02:41:27 +0200] "GET /index.php/204 HTTP/1.1" 204 4813 "-" "Mozilla/5.0 (Android) Nextcloud-android/3.11.1"                                                                         
[myPhonesAddress] - - [24/Apr/2020:02:41:27 +0200] "GET /index.php/204 HTTP/1.1" 204 4811 "-" "Mozilla/5.0 (Android) Nextcloud-android/3.11.1"                                                                         
[myPhonesAddress] - - [24/Apr/2020:02:41:28 +0200] "GET /index.php/204 HTTP/1.1" 204 4811 "-" "Mozilla/5.0 (Android) Nextcloud-android/3.11.1"                                                                         
[myPhonesAddress] - [myUser] [24/Apr/2020:02:41:28 +0200] "PROPFIND /remote.php/webdav/ HTTP/1.1" 207 4604 "-" "Mozilla/5.0 (Android) Nextcloud-android/3.11.1"                                                          
[myPhonesAddress] - [myUser] [24/Apr/2020:02:41:30 +0200] "PROPFIND /remote.php/webdav/[myCalendar]/ HTTP/1.1" 207 1000 "-" "Mozilla/5.0 (Android) Nextcloud-android/3.11.1"                                               
[myPhonesAddress] - [myUser] [24/Apr/2020:02:41:31 +0200] "PROPFIND /remote.php/dav/calendars/[myUser]/[myCalendar]/ HTTP/1.1" 207 5770 "-" "DAVx5/3.0-gplay (2020/04/22; dav4jvm; okhttp/4.5.0) Android/7.1.2"                  
[myPhonesAddress] - [myUser] [24/Apr/2020:02:41:31 +0200] "PROPFIND /remote.php/dav/calendars/[myUser]/[myCalendar]/ HTTP/1.1" 207 6661 "-" "DAVx5/3.0-gplay (2020/04/22; dav4jvm; okhttp/4.5.0) Android/7.1.2"

Web server error log

[Thu Apr 23 10:49:07.818311 2020] [access_compat:error] [pid 2005] [client 192.168.1.2:54136] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 12:57:31.275591 2020] [access_compat:error] [pid 5589] [client 192.168.1.3:51262] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 13:02:27.998105 2020] [access_compat:error] [pid 6614] [client 192.168.1.2:56134] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 13:12:46.539458 2020] [access_compat:error] [pid 1503] [client 192.168.1.3:51722] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 13:13:18.046659 2020] [access_compat:error] [pid 2024] [client 192.168.1.3:51726] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 13:13:50.097072 2020] [access_compat:error] [pid 1576] [client 192.168.1.3:51730] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 13:14:22.118194 2020] [access_compat:error] [pid 1504] [client 192.168.1.3:51736] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 13:14:34.103379 2020] [access_compat:error] [pid 2069] [client 192.168.1.3:51740] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 20:21:13.551648 2020] [access_compat:error] [pid 6127] [client 192.168.1.2:60596] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 20:44:42.981675 2020] [access_compat:error] [pid 7097] [client 192.168.1.2:33316] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 20:52:40.945870 2020] [access_compat:error] [pid 7345] [client 192.168.1.2:33536] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 21:13:15.481716 2020] [access_compat:error] [pid 8002] [client 192.168.1.2:34250] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 23:25:33.026165 2020] [access_compat:error] [pid 9521] [client 192.168.1.3:41102] AH01797: client denied by server configuration: /data/nextcloud/app/config                                         
[Thu Apr 23 23:46:32.576097 2020] [negotiation:error] [pid 10277] [client 192.168.1.3:41974] AH00687: Negotiation: discovered file(s) matching request: /data/nextcloud/app/data/nextcloud (None could be negotia
[Fri Apr 24 01:08:35.404103 2020] [access_compat:error] [pid 11827] [client 192.168.1.2:52662] AH01797: client denied by server configuration: /data/nextcloud/app/config

Nextcloud log (data/nextcloud.log)

{"reqId":"GHTEUZj0b5hgF4YIpnLk","level":0,"time":"2020-04-23T22:06:19+00:00","remoteAddr":"[myAddress]","user":"--","app":"webdav","method":"OPTIONS","url":"/remote.php/dav/calendars/[myUser]/[myCalendar]/","message":{"Exception":"Sabre\\DAV\\Exception\\NotFound","Message":"File with name /calendars could not be located","Code":0,"Trace":[{"file":"/data/nextcloud/app/3rdparty/sabre/dav/lib/DAV/Tree.php","line":68,"function":"getChild","class":"Sabre\\DAV\\FS\\Directory","type":"->","args":["calendars"]},{"file":"/data/nextcloud/app/3rdparty/sabre/dav/lib/DAV/Tree.php","line":71,"function":"getNodeForPath","class":"Sabre\\DAV\\Tree","type":"->","args":["calendars"]},{"file":"/data/nextcloud/app/3rdparty/sabre/dav/lib/CalDAV/Plugin.php","line":76,"function":"getNodeForPath","class":"Sabre\\DAV\\Tree","type":"->","args":["calendars/[myUser]"]},{"file":"/data/nextcloud/app/3rdparty/sabre/dav/lib/DAV/Server.php","line":535,"function":"getHTTPMethods","class":"Sabre\\CalDAV\\Plugin","type":"->","args":["calendars/[myUser]/[myCalendar]"]},{"file":"/data/nextcloud/app/3rdparty/sabre/dav/lib/DAV/CorePlugin.php","line":212,"function":"getAllowedMethods","class":"Sabre\\DAV\\Server","type":"->","args":["calendars/[myUser]/[myCalendar]"]},{"file":"/data/nextcloud/app/apps/dav/lib/Connector/Sabre/AnonymousOptionsPlugin.php","line":75,"function":"httpOptions","class":"Sabre\\DAV\\CorePlugin","type":"->","args":[{"absoluteUrl":"https://my.domain.de/remote.php/dav/calendars/[myUser]/[myCalendar]/","__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"function":"handleAnonymousOptions","class":"OCA\\DAV\\Connector\\Sabre\\AnonymousOptionsPlugin","type":"->","args":[{"absoluteUrl":"https://my.domain.de/remote.php/dav/calendars/[myUser]/[myCalendar]/","__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/data/nextcloud/app/3rdparty/sabre/event/lib/EventEmitterTrait.php","line":105,"function":"call_user_func_array","args":[[{"__class__":"OCA\\DAV\\Connector\\Sabre\\AnonymousOptionsPlugin"},"handleAnonymousOptions"],[{"absoluteUrl":"https://my.domain.de/remote.php/dav/calendars/[myUser]/[myCalendar]/","__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]]},{"file":"/data/nextcloud/app/3rdparty/sabre/dav/lib/DAV/Server.php","line":466,"function":"emit","class":"Sabre\\Event\\EventEmitter","type":"->","args":["beforeMethod",[{"absoluteUrl":"https://my.domain.de/remote.php/dav/calendars/[myUser]/[myCalendar]/","__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]]},{"file":"/data/nextcloud/app/3rdparty/sabre/dav/lib/DAV/Server.php","line":254,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->","args":[{"absoluteUrl":"https://my.domain.de/remote.php/dav/calendars/[myUser]/[myCalendar]/","__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"/data/nextcloud/app/apps/dav/lib/Server.php","line":319,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"/data/nextcloud/app/apps/dav/appinfo/v2/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->","args":[]},{"file":"/data/nextcloud/app/remote.php","line":165,"args":["/data/nextcloud/app/apps/dav/appinfo/v2/remote.php"],"function":"require_once"}],"File":"/data/nextcloud/app/3rdparty/sabre/dav/lib/DAV/FS/Directory.php","Line":76,"CustomMessage":"--"},"userAgent":"Evolution/3.28.5","version":"18.0.4.2"}

3. to review bug

Source

Hobbes921

Most helpful comment

I don't have to explain why randomly removing lines related to authorisation is a bad idea, do i?

georgehrke on 24 Apr 2020

👍4

All 16 comments

I can confirm this bug. I see the same errors (an OPTION request for calendars returning 404) after upgrading from 18.0.3 to 18.0.4. This occurs both with Evolution and with some other caldav tools I use, such as my emacs caldav integration (org-caldav).

Both systems were successfully communicating with nextcloud calendars with server version 18.0.3 earlier today.

alraban on 24 Apr 2020

cc @nextcloud/calendar

kesselb on 24 Apr 2020

I can also confirm this bug.
After commenting out the following lines, the sync works again:

$emptyAuth = $request->getHeader('Authorization') === null || $request->getHeader('Authorization') === '' || trim($request->getHeader('Authorization')) === 'Bearer';

dst21 on 24 Apr 2020

👍1

I don't have to explain why randomly removing lines related to authorisation is a bad idea, do i?

georgehrke on 24 Apr 2020

👍4

I have compared those file with it from nextcloud version 18.0.3 and this are the only changes.
Without commenting it out, my z-push doesn't work.

dst21 on 24 Apr 2020

It seems that isRequestInRoot is now missing for isAnonymousOptions: https://github.com/nextcloud/server/commit/8fba05db965f188ff49705af5b55eef87373dd8d#diff-8f0aff0a02f5b37de83d175302bb0fad

cc @juliushaertl

kesselb on 24 Apr 2020

As far as i can tell, this issue also affects macOS Addressbook:

[24/Apr/2020:12:33:30 +0200] "OPTIONS /remote.php/dav/principals/users/georg/ HTTP/1.0" 404 239 "-" "Mac OS X/10.15.4 (19E287) AddressBookCore/1"

georgehrke on 24 Apr 2020

👍2

Could you check if https://github.com/nextcloud/server/pull/20632 fixes the issue?

juliushaertl on 24 Apr 2020

That change appears to fix the issue, at least with evolution and org-caldav. Thanks for the quick action!

alraban on 24 Apr 2020

❤2

@juliushaertl
Yes, this fixes the issue on my setup.
Thanks!

Hobbes921 on 24 Apr 2020

Also this fixed this issue on my server.
Thanks.

dst21 on 24 Apr 2020

I have the same issue with Z-Push. Only CalDAV is affected while CardDAV works proprely.

I've just restored the apps/dav/lib/Connector/Sabre/AnonymousOptionsPlugin.php from my backup which made it work again.

I guess that is not the best idea but maybe it's a good workaround until the issue is fixed with the next update. The workaround also passes the nextcloud integrity checks!

cm91 on 25 Apr 2020

Could you check if #20632 fixes the issue?

@juliushaertl this also fixes macOS Catalina CardDAV sync.

joostdekeijzer on 26 Apr 2020

Fix is in #20632

MorrisJobke on 27 Apr 2020

@juliushaertl this also fixes macOS High Sierra CardDAV sync. Since this breach has so tremendous effect, please think over to push it soon.

cbean on 27 Apr 2020

Aha. This is what has been keeping me from syncing from org-caldav. I run my nextcloud server on an ubuntu snap package.

$ snap list
Name       Version      Rev    Tracking       Publisher   Notes
core       16-2.44.3    9066   latest/stable  canonical✓  core
nextcloud  18.0.4snap1  20498  latest/stable  nextcloud✓  -

What does one do to pull the fix in?