CalDAV PUT Event shows irregular behavior

freumichCH · May 31, 2019, 10:32am

Hi Guys!

i’m currently observing a really strange behavior in the Calendar-App and its synchronisation mechanism.
Auto Discovery and Downloading already existing events working like expected. So i would say, that apache and haproxy is konfigured properly.

If i add a new event, as example on my iPad, it starts puting the ICS to the Server. in 2 of 10 times does it work like expected. in the rest of 8 events i get following error in the nextcloud.log

The Apache access.log shows a Error 500
10.0.59.101 - caldavtester [31/May/2019:09:38:00 +0000] “PUT /remote.php/dav/calendars/caldavtester/work/04900E0F-1BE1-4389-AB6C-677417025A30.ics HTTP/1.1” 500 823 “-” “iOS/12.1 (16B92) dataaccessd/1.0”

{"reqId":"eSulVwwLxmLmi1oFlkqx","level":4,"time":"2019-05-31T11:51:28+02:00","remoteAddr":"84.226.xxx.xxx","user":"caldavtester","app":"webdav","method":"PUT","url":"\/remote.php\/dav\/calendars\/caldavtester\/work\/42E72FCF-3E1B-43C1-8C66-A356DB55F82C.ics","message":{"Exception":"InvalidArgumentException","Message":"Calendarobject does not exists: 42E72FCF-3E1B-43C1-8C66-A356DB55F82C.ics","Code":0,"Trace":[{"file":"\/var\/www\/nextcloud\/apps\/dav\/lib\/CalDAV\/CalDavBackend.php","line":2404,"function":"getCalendarObjectId","class":"OCA\\DAV\\CalDAV\\CalDavBackend","type":"->","args":["*** sensitive parameter replaced ***","*** sensitive parameter replaced ***","*** sensitive parameter replaced ***"]},{"file":"\/var\/www\/nextcloud\/apps\/dav\/lib\/CalDAV\/CalDavBackend.php","line":1080,"function":"updateProperties","class":"OCA\\DAV\\CalDAV\\CalDavBackend","type":"->","args":["*** sensitive parameters replaced ***"]},{"file":"\/var\/www\/nextcloud\/3rdparty\/sabre\/dav\/lib\/CalDAV\/Calendar.php","line":201,"function":"createCalendarObject","class":"OCA\\DAV\\CalDAV\\CalDavBackend","type":"->","args":["*** sensitive parameter replaced ***","*** sensitive parameter replaced ***","*** sensitive parameter replaced ***"]},{"file":"\/var\/www\/nextcloud\/3rdparty\/sabre\/dav\/lib\/DAV\/Server.php","line":1096,"function":"createFile","class":"Sabre\\CalDAV\\Calendar","type":"->","args":["*** sensitive parameter replaced ***","*** sensitive parameter replaced ***"]},{"file":"\/var\/www\/nextcloud\/3rdparty\/sabre\/dav\/lib\/DAV\/CorePlugin.php","line":525,"function":"createFile","class":"Sabre\\DAV\\Server","type":"->","args":["calendars\/caldavtester\/work\/42E72FCF-3E1B-43C1-8C66-A356DB55F82C.ics","*** sensitive parameter replaced ***",null]},{"function":"httpPut","class":"Sabre\\DAV\\CorePlugin","type":"->","args":[{"absoluteUrl":"http:\/\/developer.mynextcloud.tld\/remote.php\/dav\/calendars\/caldavtester\/work\/42E72FCF-3E1B-43C1-8C66-A356DB55F82C.ics","__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"\/var\/www\/nextcloud\/3rdparty\/sabre\/event\/lib\/EventEmitterTrait.php","line":105,"function":"call_user_func_array","args":[[{"__class__":"Sabre\\DAV\\CorePlugin"},"httpPut"],[{"absoluteUrl":"http:\/\/developer.mynextcloud.tld\/remote.php\/dav\/calendars\/caldavtester\/work\/42E72FCF-3E1B-43C1-8C66-A356DB55F82C.ics","__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]]},{"file":"\/var\/www\/nextcloud\/3rdparty\/sabre\/dav\/lib\/DAV\/Server.php","line":479,"function":"emit","class":"Sabre\\Event\\EventEmitter","type":"->","args":["method:PUT",[{"absoluteUrl":"http:\/\/developer.mynextcloud.tld\/remote.php\/dav\/calendars\/caldavtester\/work\/42E72FCF-3E1B-43C1-8C66-A356DB55F82C.ics","__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]]},{"file":"\/var\/www\/nextcloud\/3rdparty\/sabre\/dav\/lib\/DAV\/Server.php","line":254,"function":"invokeMethod","class":"Sabre\\DAV\\Server","type":"->","args":[{"absoluteUrl":"http:\/\/developer.mynextcloud.tld\/remote.php\/dav\/calendars\/caldavtester\/work\/42E72FCF-3E1B-43C1-8C66-A356DB55F82C.ics","__class__":"Sabre\\HTTP\\Request"},{"__class__":"Sabre\\HTTP\\Response"}]},{"file":"\/var\/www\/nextcloud\/apps\/dav\/lib\/Server.php","line":301,"function":"exec","class":"Sabre\\DAV\\Server","type":"->","args":[]},{"file":"\/var\/www\/nextcloud\/apps\/dav\/appinfo\/v2\/remote.php","line":35,"function":"exec","class":"OCA\\DAV\\Server","type":"->","args":[]},{"file":"\/var\/www\/nextcloud\/remote.php","line":163,"args":["\/var\/www\/nextcloud\/apps\/dav\/appinfo\/v2\/remote.php"],"function":"require_once"}],"File":"\/var\/www\/nextcloud\/apps\/dav\/lib\/CalDAV\/CalDavBackend.php","Line":2569,"CustomMessage":"--"},"userAgent":"iOS\/12.1 (16B92) dataaccessd\/1.0","version":"15.0.7.0"}

As you can see, there is a message saying that the Exception occured:
InvalidArgumentException",“Message”:"Calendarobject does not exists: 42E72FCF-3E1B-43C1-8C66-A356DB55F82C.ics

Has anyone ideas why it does sometimes work and sometimes not?

My Config:
Apache (nextcloud.conf)
<Directory /var/www/nextcloud/>
Options +FollowSymlinks
AllowOverride All

Dav off RewriteEngine on RewriteRule ^/\.well-known/host-meta /public.php?service=host-meta [QSA,L] RewriteRule ^/\.well-known/host-meta\.json /public.php?service=host-meta-json [QSA,L] RewriteRule ^/\.well-known/webfinger /public.php?service=webfinger [QSA,L] RewriteRule ^/\.well-known/carddav /remote.php/dav/ [R=301,L] RewriteRule ^/\.well-known/caldav /remote.php/dav/ [R=301,L]

SetEnv HOME /var/www/nextcloud
SetEnv HTTP_HOME /var/www/nextcloud

Satisfy Any

Site note: I tested this with a single apache Server behind a haproxy with ssl termination.

EDIT:
Hitting the Update Button on the Calendar WebGUI does fix the problem for single event
Also editing the event from the Source Device or WebGui does solve it. i’m realy confused now

georgehrke · May 31, 2019, 5:10pm

Do you also use some kind of load balancing for the database? I suspect the error in that area.

freumichCH · May 31, 2019, 6:17pm

Hello @georgehrke

Good point. We have a SQLProxy in front of a Cluster who’s doing a Read Write Split. The whole Database Cluster runs on SSD’s and basically there is running everything fine. (no Lags)

Do you have any ideas where i have to start my troubleshooting for that issue?

georgehrke · May 31, 2019, 6:33pm

Basically, the event is inserted into the database and it immediately tries to query it after inserting. It’s probably querying not on the master SQL but on a read-only replica, where the change was not yet propagated.

freumichCH · May 31, 2019, 9:25pm

Hello @georgehrke

Thanks again for your input, what makes absolutely sense.
I’m thinking about to separate the Calendar Table to a separate SQL node and reconfigure ProxySQL to read and write the calendar data to that node. May there is also another way to solve this issue.
I’m just thinking about big instances who serve hundert of tousends of clients.

You as a calendar app developer has for shure faced similar Problems while developing. Can you give my hint in witch direction i have to think?

i would realy apreciate it.

Thanks in advance!

freumichCH · June 4, 2019, 9:18pm

Hello Guys
The problem is solved!
I redirect all oc_calendar SELECT’s to the Master SQL Node via proxySQL.

Thanks to @georgehrke for giving me the right direction.