400 Bad Request: Overwritten recurrence with RRULESET

[kousu]

Hi all! I'm a long time user of DAVx5 and I'm really pleased with the freedom it gives me overall. I'm using SimpleCalendar + DAVx5 + radicale.

I have a bug 🐞 . Lately, I've started getting sync failures with "400 Bad Request". Some of my events sync but one of them fails and then the rest stay unsynced until I delete the bad event. I get these screens which I expect you're familiar with

and

Eventually, I figured out how to turn up debugging on my server and found the exception is

ValueError: Overwritten recurrence with RRULESET

which seems to be radicale objecting to multiple incompatible event repetitions (RRULEs) in the buggy event.

Reproducing

I don't know exactly how to reproduce this. I know I did edit the recurrence on this particular event a couple of times, but I don't know exactly what order I did things in. I've had this happen before though, and those times I just deleted the buggy event and hoped it wouldn't come back. This time I'm reporting what I know so at least there's somewhere to start solving it!

Discussion

I'm not sure whose issue this is. I think radicale is probably doing the right thing here by rejecting the weird event, which means it's either SimpleCalendar's fault for generating the weird event and/or DAVx5's for accepting it. Though, does DAVx5 have an opportunity to reject an event when saved by the calendar app?

If it does, I think it should reject broken events like this, the same way radicale is. That is, DAVx5 should port this logic into itself. That way the event will become uneditable, while leaving other events still syncable, instead of most (all?) events becoming surprise unsyncable. And then it will be possible to convince SimpleCalendar to fix their recurrence logic to avoid this case in the first place.

Logs

Client Side UI

I don't see multiple repetition definitions in the event; there's no way to tell from the UI there's a problem until the sync fails:

Client Side Logs

Here's the client side logs; I'm only including the first part because there's personal details in the rest, but I have the rest of davx5-debug.zip if you need them and I can audit them more carefully to strip out details if sharing them would be helpful.

debug-info.txt

--- BEGIN DEBUG INFO ---

SYNCHRONIZATION INFO
Account: Account {name=nick@kousu.ca, type=bitfire.at.davdroid}
Authority: com.android.calendar

EXCEPTION
at.bitfire.dav4jvm.exception.HttpException: HTTP 400 Bad Request
	at at.bitfire.dav4jvm.DavResource.checkStatus(DavResource.kt:5)
	at at.bitfire.dav4jvm.DavResource.checkStatus(DavResource.kt:3)
	at at.bitfire.dav4jvm.DavResource.put(DavResource.kt:2)
	at at.bitfire.dav4jvm.DavResource.put$default(DavResource.kt:1)
	at at.bitfire.davdroid.syncadapter.SyncManager$uploadDirty$3.invoke(SyncManager.kt:5)
	at at.bitfire.davdroid.syncadapter.SyncManager$uploadDirty$3.invoke(SyncManager.kt:1)
	at at.bitfire.davdroid.syncadapter.SyncManager.remoteExceptionContext(SyncManager.kt:1)
	at at.bitfire.davdroid.syncadapter.SyncManager.uploadDirty(SyncManager.kt:16)
	at at.bitfire.davdroid.syncadapter.SyncManager$uploadDirty$1$1$1.invoke(SyncManager.kt:2)
	at at.bitfire.davdroid.syncadapter.SyncManager$uploadDirty$1$1$1.invoke(SyncManager.kt:1)
	at at.bitfire.davdroid.syncadapter.SyncManager.localExceptionContext(SyncManager.kt:1)
	at at.bitfire.davdroid.syncadapter.SyncManager$uploadDirty$1$1.invokeSuspend(SyncManager.kt:2)
	at kotlin.coroutines.jvm.internal.BaseContinuationImpl.resumeWith(ContinuationImpl.kt:3)
	at kotlinx.coroutines.DispatchedTask.run(DispatchedTask.kt:18)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1167)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:641)
	at java.lang.Thread.run(Thread.java:919)

HTTP REQUEST
Request{method=PUT, url=https://pim.kousu.ca:5232/kousu/49e46e0e-9a17-a205-088b-ad61d3326b99/44fe7d67-516b-4ada-94d9-48095dc71c71.ics, headers=[If-Match:"a2bfdbf2248476b52e0fba2236350004b2becdca9afd87b04192da46c361ba30", User-Agent:DAVx5/4.2.1-ose (2022/05/08; dav4jvm; okhttp/4.9.3) Android/10, Accept-Language:en-CA, en;q=0.7, *;q=0.5]}
BEGIN:VCALENDAR
VERSION:2.0
PRODID:DAVx5/4.2.1-ose ical4j/3.1.2 (com.simplemobiletools.calendar.pro)
BEGIN:VEVENT
DTSTAMP:20220627T020021Z
UID:44fe7d67-516b-4ada-94d9-48095dc71c71
SEQUENCE:1
SUMMARY:Data R&D
DTSTART;TZID=America/Toronto:20220503T140000
DTEND;TZID=America/Toronto:20220503T150000
RRULE:FREQ=WEEKLY;COUNT=3;INTERVAL=1;BYDAY=TU
STATUS:CONFIRMED
ORGANIZER:mailto:nick@kousu.ca
ATTENDEE;RSVP=TRUE;CN=Nick;PARTSTAT=ACCEPTED:mailto:nick@kousu.ca
ATTENDEE;RSVP=TRUE;CUTYPE=UNKNOWN;PARTSTAT=NEEDS-ACTION:mailto:mathieu
BEGIN:VALARM
TRIGGER:-PT1H30M
ACTION:DISPLAY
DESCRIPTION:Data R&D
END:VALARM
END:VEVENT
BEGIN:VEVENT
DTSTAMP:20220627T020021Z
UID:44fe7d67-516b-4ada-94d9-48095dc71c71
RECURRENCE-ID;TZID=America/Toronto:20220517T140000
SEQUENCE:1
DTSTART;TZID=America/Toronto:19700119T220650
DTEND;TZID=America/Toronto:19700119T220654
EXDATE:20220517T040000Z
ORGANIZER:mailto:nick@kousu.ca
END:VEVENT
BEGIN:VTIMEZONE
TZID:America/Toronto
LAST-MODIFIED:20201010T011803Z
BEGIN:DAYLIGHT
TZNAME:EDT
TZOFFSETFROM:-0500
TZOFFSETTO:-0400
DTSTART:19500430T020000
RRULE:FREQ=YEARLY;UNTIL=19860427T070000Z;BYMONTH=4;BYDAY=-1SU
END:DAYLIGHT
BEGIN:STANDARD
TZNAME:EST
TZOFFSETFROM:-0400
TZOFFSETTO:-0500
DTSTART:19571027T020000
RRULE:FREQ=YEARLY;UNTIL=20061029T060000Z;BYMONTH=10;BYDAY=-1SU
END:STANDARD
BEGIN:DAYLIGHT
TZNAME:EDT
TZOFFSETFROM:-0500
TZOFFSETTO:-0400
DTSTART:19870405T020000
RRULE:FREQ=YEARLY;UNTIL=20060402T070000Z;BYMONTH=4;BYDAY=1SU
END:DAYLIGHT
BEGIN:DAYLIGHT
TZNAME:EDT
TZOFFSETFROM:-0500
TZOFFSETTO:-0400
DTSTART:20070311T020000
RRULE:FREQ=YEARLY;BYMONTH=3;BYDAY=2SU
END:DAYLIGHT
BEGIN:STANDARD
TZNAME:EST
TZOFFSETFROM:-0400
TZOFFSETTO:-0500
DTSTART:20071104T020000
RRULE:FREQ=YEARLY;BYMONTH=11;BYDAY=1SU
END:STANDARD
END:VTIMEZONE
END:VCALENDAR

Server Side Log

[2022-06-27 03:07:52 +0200] [88918/Thread-488] [INFO] PUT request for '/kousu/49e46e0e-9a17-a205-088b-ad61d3326b99/44fe7d67-516b-4ada-94d9-48095dc71c71.ics' received from 24.114.101.32 using 'DAVx5/4.2.1-ose (2022/05/08; dav4jvm; okhttp/4.9.3) Android/10'
[2022-06-27 03:07:52 +0200] [88918/Thread-488] [DEBUG] Request headers:
{'CONTENT_LENGTH': '1835',
 'CONTENT_TYPE': 'text/calendar;charset=utf-8',
 'GATEWAY_INTERFACE': 'CGI/1.1',
 'HTTP_ACCEPT_ENCODING': 'gzip',
 'HTTP_ACCEPT_LANGUAGE': 'en-CA, en;q=0.7, *;q=0.5',
 'HTTP_AUTHORIZATION': 'Basic **masked**',
 'HTTP_CONNECTION': 'Keep-Alive',
 'HTTP_HOST': 'pim.kousu.ca:5232',
 'HTTP_IF_MATCH': '"a2bfdbf2248476b52e0fba2236350004b2becdca9afd87b04192da46c361ba30"',
 'HTTP_USER_AGENT': 'DAVx5/4.2.1-ose (2022/05/08; dav4jvm; okhttp/4.9.3) '
                    'Android/10',
 'PATH_INFO': '/kousu/49e46e0e-9a17-a205-088b-ad61d3326b99/44fe7d67-516b-4ada-94d9-48095dc71c71.ics',
 'QUERY_STRING': '',
 'REMOTE_ADDR': '24.114.101.32',
 'REMOTE_CERTIFICATE': None,
 'REMOTE_HOST': '',
 'REQUEST_METHOD': 'PUT',
 'SCRIPT_NAME': '',
 'SERVER_NAME': 'comms3.kousu.ca',
 'SERVER_PORT': '5232',
 'SERVER_PROTOCOL': 'HTTP/1.1',
 'SERVER_SOFTWARE': 'WSGIServer/0.2',
 'wsgi.errors': <_io.TextIOWrapper name='<stderr>' mode='w' encoding='utf-8'>,
 'wsgi.file_wrapper': <class 'wsgiref.util.FileWrapper'>,
 'wsgi.input': <_io.BufferedReader name=7>,
 'wsgi.multiprocess': False,
 'wsgi.multithread': True,
 'wsgi.run_once': False,
 'wsgi.url_scheme': 'http',
 'wsgi.version': (1, 0)}
[2022-06-27 03:07:52 +0200] [88918/Thread-488] [DEBUG] Base prefix (from SCRIPT_NAME): ''
[2022-06-27 03:07:52 +0200] [88918/Thread-488] [DEBUG] Sanitized path: '/kousu/49e46e0e-9a17-a205-088b-ad61d3326b99/44fe7d67-516b-4ada-94d9-48095dc71c71.ics'
[2022-06-27 03:07:52 +0200] [88918/Thread-488] [INFO] Successful login: 'kousu'
[2022-06-27 03:07:52 +0200] [88918/Thread-488] [DEBUG] Request content:
BEGIN:VCALENDAR\^M
VERSION:2.0\^M
PRODID:DAVx5/4.2.1-ose ical4j/3.1.2 (com.simplemobiletools.calendar.pro)\^M
BEGIN:VEVENT\^M
DTSTAMP:20220627T010750Z\^M
UID:44fe7d67-516b-4ada-94d9-48095dc71c71\^M
SEQUENCE:1\^M
SUMMARY:Data R&D\^M
DTSTART;TZID=America/Toronto:20220503T140000\^M
DTEND;TZID=America/Toronto:20220503T150000\^M
RRULE:FREQ=WEEKLY;COUNT=3;INTERVAL=1;BYDAY=TU\^M
STATUS:CONFIRMED\^M
ORGANIZER:mailto:nick@kousu.ca\^M
ATTENDEE;RSVP=TRUE;CN=Nick;PARTSTAT=ACCEPTED:mailto:nick@kousu.ca\^M
ATTENDEE;RSVP=TRUE;CUTYPE=UNKNOWN;PARTSTAT=NEEDS-ACTION:mailto:mathieu\^M
BEGIN:VALARM\^M
TRIGGER:-PT1H30M\^M
ACTION:DISPLAY\^M
DESCRIPTION:Data R&D\^M
END:VALARM\^M
END:VEVENT\^M
BEGIN:VEVENT\^M
DTSTAMP:20220627T010750Z\^M
UID:44fe7d67-516b-4ada-94d9-48095dc71c71\^M
RECURRENCE-ID;TZID=America/Toronto:20220517T140000\^M
SEQUENCE:1\^M
DTSTART;TZID=America/Toronto:19700119T220650\^M
DTEND;TZID=America/Toronto:19700119T220654\^M
EXDATE:20220517T040000Z\^M
ORGANIZER:mailto:nick@kousu.ca\^M
END:VEVENT\^M
BEGIN:VTIMEZONE\^M
TZID:America/Toronto\^M
LAST-MODIFIED:20201010T011803Z\^M
BEGIN:DAYLIGHT\^M
TZNAME:EDT\^M
TZOFFSETFROM:-0500\^M
TZOFFSETTO:-0400\^M
DTSTART:19500430T020000\^M
RRULE:FREQ=YEARLY;UNTIL=19860427T070000Z;BYMONTH=4;BYDAY=-1SU\^M
END:DAYLIGHT\^M
BEGIN:STANDARD\^M
TZNAME:EST\^M
TZOFFSETFROM:-0400\^M
TZOFFSETTO:-0500\^M
DTSTART:19571027T020000\^M
RRULE:FREQ=YEARLY;UNTIL=20061029T060000Z;BYMONTH=10;BYDAY=-1SU\^M
END:STANDARD\^M
BEGIN:DAYLIGHT\^M
TZNAME:EDT\^M
TZOFFSETFROM:-0500\^M
TZOFFSETTO:-0400\^M
DTSTART:19870405T020000\^M
RRULE:FREQ=YEARLY;UNTIL=20060402T070000Z;BYMONTH=4;BYDAY=1SU\^M
END:DAYLIGHT\^M
BEGIN:DAYLIGHT\^M
TZNAME:EDT\^M
TZOFFSETFROM:-0500\^M
TZOFFSETTO:-0400\^M
DTSTART:20070311T020000\^M
RRULE:FREQ=YEARLY;BYMONTH=3;BYDAY=2SU\^M
END:DAYLIGHT\^M
BEGIN:STANDARD\^M
TZNAME:EST\^M
TZOFFSETFROM:-0400\^M
TZOFFSETTO:-0500\^M
DTSTART:20071104T020000\^M
RRULE:FREQ=YEARLY;BYMONTH=11;BYDAY=1SU\^M
END:STANDARD\^M
END:VTIMEZONE\^M
END:VCALENDAR\^M

[2022-06-27 03:07:52 +0200] [88918/Thread-488] [WARNING] Bad PUT request on '/kousu/49e46e0e-9a17-a205-088b-ad61d3326b99/44fe7d67-516b-4ada-94d9-48095dc71c71.ics': Overwritten recurrence with RRULESET
Traceback (most recent call last):
  File "/usr/local/lib/python3.8/site-packages/radicale/app/put.py", line 95, in prepare
    item.prepare()
  File "/usr/local/lib/python3.8/site-packages/radicale/item/__init__.py", line 470, in prepare
    self.time_range
  File "/usr/local/lib/python3.8/site-packages/radicale/item/__init__.py", line 459, in time_range
    self._time_range = find_time_range(
  File "/usr/local/lib/python3.8/site-packages/radicale/item/__init__.py", line 324, in find_time_range
    radicale_filter.visit_time_ranges(vobject_item, tag, range_fn, infinity_fn)
  File "/usr/local/lib/python3.8/site-packages/radicale/item/filter.py", line 246, in visit_time_ranges
    for child, is_recurrence, recurrences in get_children(
  File "/usr/local/lib/python3.8/site-packages/radicale/item/filter.py", line 234, in get_children
    raise ValueError("Overwritten recurrence with RRULESET")
ValueError: Overwritten recurrence with RRULESET
[2022-06-27 03:07:52 +0200] [88918/Thread-488] [DEBUG] Running storage hook
[2022-06-27 03:07:52 +0200] [88918/Thread-488] [DEBUG] Response content:
Bad Request
[2022-06-27 03:07:52 +0200] [88918/Thread-488] [INFO] PUT response status for '/kousu/49e46e0e-9a17-a205-088b-ad61d3326b99/44fe7d67-516b-4ada-94d9-48095dc71c71.ics' in 0.225 seconds: 400 Bad Request

Versions

Client Side Versions

Hardware: harpia

Android version: 10

LineageOS version: 17.1-20220209-microG-harpia (from this dead link).

DAVx5 version: 4.2.1-ose (from f-droid).

Sinmple Calendar version: 6.18.3 (from f-droid)

Server Side Versions

OS:

pim# uname -a
OpenBSD pim.kousu.ca 7.0 GENERIC#224 amd64

Calendar server: radicale installed via pip (i.e. PyPI).

pim# radicale --version                                                                                                                           
3.1.6

[sunkup]

Hey there,

and thank you for the extensive report. This is a known issue with with SimpleCalendar. The details on why this happens are discussed there.

In short: SimpleCalendar has a special way of handling exceptions. DAVx5 however treats the Android calendar provider the standard way which most other calendar apps do too.

You may consider using another CalendarApp.
Hope this helps :)

[kousu]

Thank you for taking the time to read all this and direct me and for all the time you've spent making DAVx5 :)

I guess I will go back to the stock Lineage/AOSP Calendar. I mean, that app is fine, I just wanted to try to support software diversity. Didn't SimpleCalendar get bundled as the stock Calendar into /e/? Or some other ROMs? But this lurking bug makes it a no-go for me.

[kellyclowers]

Ouch. That sucks that Simple Calendar is doing it wrong. Also it seems like really the only real OSS alternative is Etar. Not really a lot of options :-( And Simple Gallery just lost an invaluable feature too (due to Google permissions fuckery, but he doesn't have any intention of making any sort of workaround), now I am stuck on an old version...