etesync / etesync-dav

This is a CalDAV and CardDAV adapter for EteSync
https://www.etesync.com
GNU General Public License v3.0
290 stars 47 forks source link

Overwritten recurrence with RRULESET when trying to sync with Gnome Evolution #112

Open anthonymvicente opened 4 years ago

anthonymvicente commented 4 years ago

When trying to use the bridge to add my calendar to gnome evolution, I get the following errors. The first error in the stack trace occurs when I try to 'find calendars' within evolution, but it does find the calendar just fine. The last error in the stack trace occurs when I try to refresh the calendar to actually get events. The calendar never actually gets the events for my calendar, and any time I try to refresh I get the same error regarding Overwritten recurrence with RRULESET, but I can't seem to find which event it might be causing this. I'm including the full stack trace as an attachment, which shows the first error I describe.

d8f0700] WARNING: Bad REPORT request on '/anthony@mvicente.com/14789637835a61b277a04da041c66dce442ab6218faf7ec20d3c2a1879657e58/': Failed to filter item 'bad5a739cff6cca418ed5283b5ad65fd676bf1515851ca2ba59929bee43ae604.ics' from 'anthony@mvicente.com/14789637835a61b277a04da041c66dce442ab6218faf7ec20d3c2a1879657e58': Overwritten recurrence with RRULESET
Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/radicale/xmlutils.py", line 1270, in report
    if not all(match(item, filter_) for filter_ in filters):
  File "/usr/lib/python3.8/site-packages/radicale/xmlutils.py", line 1270, in <genexpr>
    if not all(match(item, filter_) for filter_ in filters):
  File "/usr/lib/python3.8/site-packages/radicale/xmlutils.py", line 1252, in match
    return _comp_match(item, filter_[0])
  File "/usr/lib/python3.8/site-packages/radicale/xmlutils.py", line 207, in _comp_match
    if not _comp_match(item, child, level=level + 1):
  File "/usr/lib/python3.8/site-packages/radicale/xmlutils.py", line 204, in _comp_match
    if not _time_range_match(item.item, filter_[0], tag):
  File "/usr/lib/python3.8/site-packages/radicale/xmlutils.py", line 279, in _time_range_match
    _visit_time_ranges(vobject_item, child_name, range_fn, infinity_fn)
  File "/usr/lib/python3.8/site-packages/radicale/xmlutils.py", line 337, in _visit_time_ranges
    for child, is_recurrence, recurrences in get_children(
  File "/usr/lib/python3.8/site-packages/radicale/xmlutils.py", line 325, in get_children
    raise ValueError("Overwritten recurrence with RRULESET")
ValueError: Overwritten recurrence with RRULESET

The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "/usr/lib/python3.8/site-packages/radicale/__init__.py", line 981, in do_REPORT
    status, xml_answer = xmlutils.report(
  File "/usr/lib/python3.8/site-packages/radicale/xmlutils.py", line 1273, in report
    raise ValueError("Failed to filter item %r from %r: %s" %
ValueError: Failed to filter item 'bad5a739cff6cca418ed5283b5ad65fd676bf1515851ca2ba59929bee43ae604.ics' from 'anthony@mvicente.com/14789637835a61b277a04da041c66dce442ab6218faf7ec20d3c2a1879657e58': Overwritten recurrence with RRULESET
[7f8fad8f0700] DEBUG: Response content:
Bad Request
[7f8fad8f0700] INFO: REPORT response status for '/anthony@mvicente.com/14789637835a61b277a04da041c66dce442ab6218faf7ec20d3c2a1879657e58/' with depth '1' in 6.204 seconds: 400 Bad Request

etesync-dav.txt

tasn commented 4 years ago

Sorry for the slow reply! It got lost in my inbox :|

Looking at what's going on, I suspect that you may have a malformed event. Luckily it shouldn't be too hard to figure it out.

  1. Open the management UI and navigate to the list of calendars.
  2. Then copy the link to the calendar, and append bad5a739cff6cca418ed5283b5ad65fd676bf1515851ca2ba59929bee43ae604.ics
  3. You should now have the offending ics file which we can further inspect.

Please let me know once you have more information, and sorry again for the delay. Please ping me on IRC/email the next time I'm taking too long to reply.

anthonymvicente commented 4 years ago

No worries, I had forgotten about it myself a bit... but thanks for getting back to me! I found the entry, I'm attaching it below (renamed as a .txt file because github won't allow an ics). FYI I did try deleting it from my calendar (using my phone calendar app), but I still seem to be getting the same error. Let me know if there's anything else I can do on my end. bad5a739cff6cca418ed5283b5ad65fd676bf1515851ca2ba59929bee43ae604.txt

anthonymvicente commented 4 years ago

Actually it looks like it might have just taken some time to sync, deleting the entry I attached above does allow me to setup my calendar in gnome evolution. I'm fine without that event in my calendar (was actually planning on removing it). But if there's anything else you need from me to look into this error more, just let me know. Thanks for the help!

tasn commented 4 years ago

Glad to hear it works, I'll take a look at the event and try to figure it out. :)

Just a funny thing I just noticed: the event's id starts with the word "bad". It was its destiny to fail. ;)

tasn commented 4 years ago

I took a look at the file, and it looks fine to me. Additionally, I tried searching radicale for this error, and indeed this error doesn't seem relevant for this event. Here is the relevant ticket: https://github.com/Kozea/Radicale/issues/700 I wonder what's going on. :|

anthonymvicente commented 4 years ago

Glad to hear it works, I'll take a look at the event and try to figure it out. :)

Just a funny thing I just noticed: the event's id starts with the word "bad". It was its destiny to fail. ;)

Even crazier was that it was an event that was set to happen the day you got back to me.

I took a look at the file, and it looks fine to me. Additionally, I tried searching radicale for this error, and indeed this error doesn't seem relevant for this event. Here is the relevant ticket: Kozea/Radicale#700 I wonder what's going on. :|

Very weird... At least deleting it fixed it. Thanks again, I appreciate the help! Should I close this issue then? While the underlying cause wasn't really fixed, it's not really an issue anymore.

tasn commented 4 years ago

Even crazier was that it was an event that was set to happen the day you got back to me.

There's some weird voodoo going on with this ticket. :P

Very weird... At least deleting it fixed it. Thanks again, I appreciate the help! Should I close this issue then? While the underlying cause wasn't really fixed, it's not really an issue anymore.

I think I'll keep it open until I get a chance to properly investigate what is going on. Glad to hear we got it sorted out though. :)

chasewinnings391 commented 4 years ago

I got a similar issue. I'm trying to setup Evolution for the first time on Ubuntu 19.10. In Evolution I get the error "The reported error was “Failed to issue REPORT: HTTP error code 400 (Bad Request): Bad Request”.

 ./linux-etesync-dav
 * Serving Flask app "etesync_dav.webui" (lazy loading)
 * Environment: production
   WARNING: This is a development server. Do not use it in a production deployment.
   Use a production WSGI server instead.
 * Debug mode: off
 * Running on http://127.0.0.1:37359/ (Press CTRL+C to quit)
127.0.0.1 - - [04/Mar/2020 23:04:35] "GET /user/myemailaddress%40domain.com HTTP/1.1" 302 -
127.0.0.1 - - [04/Mar/2020 23:04:35] "GET /login/ HTTP/1.1" 200 -
127.0.0.1 - - [04/Mar/2020 23:04:38] "POST /login/ HTTP/1.1" 302 -
127.0.0.1 - - [04/Mar/2020 23:04:38] "GET / HTTP/1.1" 200 -
[7f42c5ecc700] WARNING: Bad REPORT request on '/myemailaddress@domain.com/b9a891e3828e09d08f0ed84dc66a579539f3d82536399c05bb8d06e8b7cbff97/': Failed to filter item '3e957c71835c22e1382e1550e2ff347138f1e4dbcd099a80893585cf20fe4f06.ics' from 'myemailaddress@domain.com/b9a891e3828e09d08f0ed84dc66a579539f3d82536399c05bb8d06e8b7cbff97': Main component missing
tasn commented 4 years ago

It looks like exactly the same issue as discussed in both https://github.com/Kozea/Radicale/issues/700 and in the related https://github.com/Kozea/Radicale/issues/715

Looking there, it looks like you have an event with a recurrence-id although it's actually the main event, and not just one recurrence. The solution would be to remove the offending event from e.g. the web client. To find out which event it is you can go to https://client.etesync.com/debug and enter b9a891e3828e09d08f0ed84dc66a579539f3d82536399c05bb8d06e8b7cbff97 as the journal id and you can try 3e957c71835c22e1382e1550e2ff347138f1e4dbcd099a80893585cf20fe4f06 as the entry id. If you can paste this one here (after you anonymise it a bit), that would be great. Though anyhow, that should be enough information for you to find the relevant entry and remove it.

chasewinnings391 commented 4 years ago

Thanks for your help! I managed to find out which calendar event was causing problem. Deleting the event solved it!

I wasn't able to find the event through the debug link, so unfortunately I can't give you any more information.

tasn commented 4 years ago

Ah damn, I was just going to say how much I love the debug link. :)

Anyhow, if you deleted the event it should now be at the top of your journal, could you maybe share it (again, please anonymise as needed).

chasewinnings391 commented 4 years ago

Yes, you are right! I found the deleted event at the top of the journal. Here are the details of the event. Hope it can be of some use for you :)

BEGIN:VCALENDAR
PRODID:-//iCal.js EteSync iOS
VERSION:2.0
BEGIN:VEVENT
DTSTART;VALUE=DATE:20140519
DTEND;VALUE=DATE:20140520
DTSTAMP:20200107T095407Z
UID:2ismv5vjvujv5h4rbt8nvdcu6g@google.com
RECURRENCE-ID;VALUE=DATE:20140419
CREATED:20140304T131553Z
DESCRIPTION:
LAST-MODIFIED:20150412T215345Z
LOCATION:
SEQUENCE:2
STATUS:CONFIRMED
SUMMARY:Somebody's birthday
TRANSP:TRANSPARENT
END:VEVENT
END:VCALENDAR
tasn commented 4 years ago

Thanks for sharing. Interestingly enough, this event actually doesn't look wrong for all I see (assuming there's a related event with the full recurrence). Actually though, if you can easily find it (I guess it may be annoying, if so, never mind), could you also share the previous time this event shows up in your change journal? It would be an add or edit journal entry, when this was first added or last edited. Maybe the iOS app already fixed the issue in the data when it deleted the event.

chasewinnings391 commented 4 years ago

I believe this is the first entry of the event. The strange thing is that this event is dated on 19-04-2014, while the event which caused problems was dated one month later at 19-05-2014. Maybe that is the reason the event couldn't be imported into Evolution?

BEGIN:VCALENDAR
PRODID:-//iCal.js EteSync iOS
VERSION:2.0
BEGIN:VEVENT
DTSTART;VALUE=DATE:20140419
DTEND;VALUE=DATE:20140420
RRULE:FREQ=YEARLY;WKST=MO;UNTIL=20150418
DTSTAMP:20200107T095407Z
UID:2ismv5vjvujv5h4rbt8nvdcu6g@google.com
CREATED:20140304T131553Z
DESCRIPTION:
LAST-MODIFIED:20150412T215345Z
LOCATION:
SEQUENCE:0
STATUS:CONFIRMED
SUMMARY: Somebody's birthday
TRANSP:TRANSPARENT
END:VEVENT
END:VCALENDAR

I looked up the original event since it is imported from gmail. On gmail the event is dated on 19-05-2014 while it is supposed to recur every year on the 19th of April. This doesn't really make sense to me. So I guess gmail is the main source of the trouble here.

recurring event

tasn commented 4 years ago

Interesting. This event actually looks right too. One more thing you can check is: Open the web management ui: http://localhost:37358 go to the journal, and click to download the .ics file. Then look for this event's uid: 2ismv5vjvujv5h4rbt8nvdcu6g@google.com

Do you see any other events with the same uid?

chasewinnings391 commented 4 years ago

I tried, but going to http://localhost:37358 simply redirects to http://localhost:37359, which is the management UI.

tasn commented 4 years ago

Yeah, the management UI is on 37359 (though it changed in the latest version of etesync-dav!), though the 37358 (which is the main port) redirects there when you connect to the browser, so I always mention that one.

Have you managed to find the event?

tasn commented 4 years ago

I've investigated this further, and it seems to be an issue with events that have a recurrence-id but also rrule set. I guess it's related to https://stackoverflow.com/questions/11456406/recurrence-id-in-icalendar-rfc-5545 In essence, you shouldn't have rrule and recurrence-id set at the same time. At least not according to radicale. I wonder where the data originally came from.