Calendar sync should continue with next item on error

Bug Reports
#1

REPRODUCIBILITY (% or how often): 100%
BUILD ID:
HARDWARE (Jolla1, Tablet, XA2,…): Xperia X (probably irrelevant)
UI LANGUAGE: English (irrelevant)
REGRESSION: (compared to previous public release: Yes, No, ?): ?

DESCRIPTION:

I just missed an appointment (AGAIN) because the CalDAV sync broke down AGAIN. Now I realize many of the related bugs have been fixed, but this is a pretty fundamental one. The problem is that an error response from the server apparently stops the entire sync process dead (see log excerpt below).

PRECONDITIONS:

So it appears I have an event in my local calendar that the server considers invalid. I received it via an email invitation, so I guess there’s really no way to make sure these things will be accepted by every server.

STEPS TO REPRODUCE:

Get the server to send an error response on some event in the local calendar (e.g. have an ill-formatted event in the calendar).

EXPECTED RESULT:

A notice should be put ON THE AFFECTED EVENT (in the calendar!) saying that it couldn’t be synced to the server, and an error message should be escalated to the global notification UI. Synchronization should then continue with the next event (!!)

ACTUAL RESULT:

Calendar synchronization simply stops dead at the event, failing to synchronize any later events, both to and from the server.

ADDITIONAL INFORMATION:

[D] unknown:0 - “---------------------------------------------------------------------”
[D] unknown:0 - “If-None-Match : *”
[D] unknown:0 - “Content-Length : 3107”
[D] unknown:0 - “Content-Type : text/calendar; charset=utf-8”
[D] unknown:0 - “URL = ETCETCBLABLA”
[D] unknown:0 - “Request : PUT”
[D] unknown:0 - "BEGIN:VCALENDAR "
[D] unknown:0 - "PRODID:-//K Desktop Environment//NONSGML libkcal 4.3//EN "
[D] unknown:0 - "VERSION:2.0 "
[D] unknown:0 - "X-KDE-ICAL-IMPLEMENTATION-VERSION:1.0 "
[D] unknown:0 - "BEGIN:VTIMEZONE "
[D] unknown:0 - "TZID:Europe/Berlin "
[D] unknown:0 - "BEGIN:STANDARD "
[D] unknown:0 - "TZNAME:CET "
[D] unknown:0 - "TZOFFSETFROM:+005328 "
[D] unknown:0 - "TZOFFSETTO:+0100 "
[D] unknown:0 - "DTSTART:20380119T031408 "
[D] unknown:0 - "RDATE:20380119T031408 "
[D] unknown:0 - "END:STANDARD "
[D] unknown:0 - "BEGIN:DAYLIGHT "
[D] unknown:0 - "TZNAME:CEST "
[D] unknown:0 - "TZOFFSETFROM:+0100 "
[D] unknown:0 - "TZOFFSETTO:+0200 "
[D] unknown:0 - "DTSTART:19810329T020000 "
[D] unknown:0 - "RRULE:FREQ=YEARLY;BYDAY=-1SU;BYMONTH=3 "
[D] unknown:0 - "END:DAYLIGHT "
[D] unknown:0 - "BEGIN:DAYLIGHT "
[D] unknown:0 - "TZNAME:CEST "
[D] unknown:0 - "TZOFFSETFROM:+0100 "
[D] unknown:0 - "TZOFFSETTO:+0200 "
[D] unknown:0 - "DTSTART:19160501T220000 "
[D] unknown:0 - "RDATE:19160501T220000 "
[D] unknown:0 - "RDATE:19170416T010000 "
[D] unknown:0 - "RDATE:19180415T010000 "
[D] unknown:0 - "RDATE:19400401T010000 "
[D] unknown:0 - "RDATE:19430329T010000 "
[D] unknown:0 - "RDATE:19440403T010000 "
[D] unknown:0 - "RDATE:19450402T010000 "
[D] unknown:0 - "RDATE:19460414T010000 "
[D] unknown:0 - "RDATE:19470407T020000 "
[D] unknown:0 - "RDATE:19480418T010000 "
[D] unknown:0 - "RDATE:19490410T010000 "
[D] unknown:0 - "RDATE:19800406T020000 "
[D] unknown:0 - "END:DAYLIGHT "
[D] unknown:0 - "BEGIN:STANDARD "
[D] unknown:0 - "TZNAME:CET "
[D] unknown:0 - "TZOFFSETFROM:+0200 "
[D] unknown:0 - "TZOFFSETTO:+0100 "
[D] unknown:0 - "DTSTART:19800928T030000 "
[D] unknown:0 - "RRULE:FREQ=YEARLY;COUNT=16;BYDAY=-1SU;BYMONTH=9 "
[D] unknown:0 - "END:STANDARD "
[D] unknown:0 - "BEGIN:STANDARD "
[D] unknown:0 - "TZNAME:CET "
[D] unknown:0 - "TZOFFSETFROM:+0200 "
[D] unknown:0 - "TZOFFSETTO:+0100 "
[D] unknown:0 - "DTSTART:19961027T030000 "
[D] unknown:0 - "RRULE:FREQ=YEARLY;BYDAY=-1SU;BYMONTH=10 "
[D] unknown:0 - "END:STANDARD "
[D] unknown:0 - "BEGIN:STANDARD "
[D] unknown:0 - "TZNAME:CET "
[D] unknown:0 - "TZOFFSETFROM:+0200 "
[D] unknown:0 - "TZOFFSETTO:+0100 "
[D] unknown:0 - "DTSTART:19161001T230000 "
[D] unknown:0 - "RDATE:19161001T230000 "
[D] unknown:0 - "RDATE:19170917T020000 "
[D] unknown:0 - "RDATE:19180916T020000 "
[D] unknown:0 - "RDATE:19421102T020000 "
[D] unknown:0 - "RDATE:19431004T020000 "
[D] unknown:0 - "RDATE:19441002T020000 "
[D] unknown:0 - "RDATE:19451118T020000 "
[D] unknown:0 - "RDATE:19461007T020000 "
[D] unknown:0 - "RDATE:19471005T020000 "
[D] unknown:0 - "RDATE:19481003T020000 "
[D] unknown:0 - "RDATE:19491002T020000 "
[D] unknown:0 - "END:STANDARD "
[D] unknown:0 - "BEGIN:DAYLIGHT "
[D] unknown:0 - "TZNAME:CEMT "
[D] unknown:0 - "TZOFFSETFROM:+0200 "
[D] unknown:0 - "TZOFFSETTO:+0300 "
[D] unknown:0 - "DTSTART:19450525T000000 "
[D] unknown:0 - "RDATE:19450525T000000 "
[D] unknown:0 - "RDATE:19470511T020000 "
[D] unknown:0 - "END:DAYLIGHT "
[D] unknown:0 - "BEGIN:DAYLIGHT "
[D] unknown:0 - "TZNAME:CEST "
[D] unknown:0 - "TZOFFSETFROM:+0300 "
[D] unknown:0 - "TZOFFSETTO:+0200 "
[D] unknown:0 - "DTSTART:19450925T000000 "
[D] unknown:0 - "RDATE:19450925T000000 "
[D] unknown:0 - "RDATE:19470630T000000 "
[D] unknown:0 - "END:DAYLIGHT "
[D] unknown:0 - "END:VTIMEZONE "
[D] unknown:0 - "BEGIN:VEVENT "
[D] unknown:0 - "ORGANIZER:MAILTO:ETCETCBLABLA "
[D] unknown:0 - "DTSTAMP:20200525T154306Z "
[D] unknown:0 - "ATTENDEE;CN=^‘ETCETCBLABLA^’;RSVP=TRUE;PARTSTAT=NEEDS-ACTION; "
[D] unknown:0 - " ROLE=REQ-PARTICIPANT;X-UID=ETCETCBLABLA "
[D] unknown:0 - "ATTENDEE;CN=^‘ETCETCBLABLA^’;RSVP=TRUE;PARTSTAT=NEEDS-ACTION; "
[D] unknown:0 - " ROLE=REQ-PARTICIPANT;X-UID=ETCETCBLABLA "
[D] unknown:0 - "ATTENDEE;CN=^‘ETCETCBLABLA^’;RSVP=TRUE;PARTSTAT=NEEDS-ACTION; "
[D] unknown:0 - " ROLE=REQ-PARTICIPANT;X-UID=ETCETCBLABLA "
[D] unknown:0 - "ATTENDEE;CN=^‘ETCETCBLABLA^’;RSVP=TRUE;PARTSTAT=NEEDS-ACTION; "
[D] unknown:0 - " ROLE=REQ-PARTICIPANT;X-UID=ETCETCBLABLA "
[D] unknown:0 - "CREATED:20200525T154128Z "
[D] unknown:0 - "UID:{922abf73-bc4f-4adf-8205-03414e8a5396} "
[D] unknown:0 - "LAST-MODIFIED:20200525T154306Z "
[D] unknown:0 - "DESCRIPTION:ETCETCBLABLA "
[D] unknown:0 - " ETCETCBLABLA "
[D] unknown:0 - " ETCETCBLABLA "
[D] unknown:0 - " ETCETCBLABLA "
[D] unknown:0 - " ETCETCBLABLA "
[D] unknown:0 - " ETCETCBLABLA "
[D] unknown:0 - “ETCETCBLABLA”
[D] unknown:0 - “ETCETCBLABLA”
[D] unknown:0 - “ETCETCBLABLA”
[D] unknown:0 - "DTSTART;TZID=Europe/Berlin:20200528T150000 "
[D] unknown:0 - "DTEND;TZID=Europe/Berlin:20200528T163000 "
[D] unknown:0 - "TRANSP:OPAQUE "
[D] unknown:0 - "END:VEVENT "
[D] unknown:0 - "END:VCALENDAR "
[D] unknown:0 - “---------------------------------------------------------------------”
[D] unknown:0 - PUT request finished: QNetworkReply::NetworkError(UnknownContentError)
[D] unknown:0 - “---------------------------------------------------------------------”
[D] unknown:0 - “PUT response status code: 415”
[D] unknown:0 - “PUT response headers:”
[D] unknown:0 - “\tDate : Thu, 09 Jul 2020 21:22:13 GMT”
[D] unknown:0 - “\tServer : Apache”
[D] unknown:0 - “\tTransfer-Encoding : chunked”
[D] unknown:0 - “\tContent-Type : application/xml; charset=utf-8”
[D] unknown:0 - “PUT response data:<?xml version=\"1.0\" encoding=\"utf-8\"?>”
[D] unknown:0 - “<d:error xmlns:d=“DAV:” xmlns:s=“http://sabredav.org/ns">"
[D] unknown:0 - " <s:exception>Sabre_DAV_Exception_UnsupportedMediaType</s:exception>”
[D] unknown:0 - " <s:message>This resource only supports valid iCalendar 2.0 data. Parse error: Invalid VObject, line 90 did not follow the icalendar/vcard format</s:message>”
[D] unknown:0 - “</d:error>”
[D] unknown:0 - “---------------------------------------------------------------------”
[W] unknown:0 - The “PUT” operation failed with error: QNetworkReply::NetworkError(UnknownContentError) : 401
[W] unknown:0 - “PUT” request failed. 401 “Network request failed with QNetworkReply::NetworkError: 299”
[W] unknown:0 - Aborting sync, “PUT” failed “Network request failed with QNetworkReply::NetworkError: 299” for notebook “ETCETCBLABLA” of account: “12”
[D] unknown:0 - Notebook sync finished. Total agents: 1
[W] unknown:0 - Aborting! Notebook synchronisation failed: 401 : “Network request failed with QNetworkReply::NetworkError: 299”
[W] unknown:0 - CalDAV sync failed: 401 “Network request failed with QNetworkReply::NetworkError: 299”
[D] unknown:0 - Session finished: “caldav-sync-12” , status: 3
[D] unknown:0 - aStatus 3
[D] unknown:0 - ProfileManager::syncProfile( “caldav-sync-12” )
[D] unknown:0 - found a valid sync profile with the given name: “caldav-sync-12”
[D] unknown:0 - Stopping the OOP process for “caldav”
[D] unknown:0 - Process “/usr/lib/buteo-plugins-qt5//oopp/caldav-client” finished with exit code 15
[D] unknown:0 - ProfileManager::syncProfile( “caldav-sync-12” )
[D] unknown:0 - found a valid sync profile with the given name: “caldav-sync-12”
[D] unknown:0 - Sync status changed for account “12”

8 Likes
Calendar-App does not show remote calendars
[release notes] Koli 4.0.1
#2

I agree for the sync not to stop process on an upload error on one event. I’m working on this, see my failure branch on git.sailfishos.org/dcaliste/buteo-sync-plugin-caldav/tree/failures.

Besides, I will try to see what’s wrong for this faulty event.

4 Likes
#3

@dcaliste Maybe the DESCRIPTION continuation line? We can’t be sure without seeing the original, though.

1 Like
#4

Thanks @Maus for the suggestion, but as you said it highly depends on the etiding done by @vmatare. In fact, the server reply is a bit informative and mentioned the line 90. Which is this one:

Looking at https://tools.ietf.org/html/rfc5545#page-108, it seems that the ATTENDEE entry is missing the : address mail value. But this may be part of the editing also. May be the quoting is faulty in the CN field.

@vmatare could you please post here the exact line ? Replace of course the name and server address of the attendee by XXX and YYY.

1 Like
#5

I’m afraid I haven’t saved the original log, and the problematic calendar event itself is of course deleted, sorry. I can try to reproduce the issue, but I don’t have time for that right now. But I’d really appreciate it if the work put into this was focused on getting the sync to continue because there’s no way to prevent these things from happening. We have only limited control over the event’s contents, and no control at all over the server, which may return errors for the weirdest reasons.

#6

Indeed, as I said in the first reply, I’m actively working on a modification to allow the sync to complete as much job as possible and don’t stop on errors. You can follow activity in my failures branch, I pushed a new commit this morning :
https://git.sailfishos.org/dcaliste/buteo-sync-plugin-caldav/activity

This needs to be done in a cautious way, because there are many assumptions in the existing code that an error stops the process. For instance, I need to pay attention that a DELETE request that is not honoured will not purge the event on device and the request will be retry at next sync… At the moment, this failure is stopping the process and nothing is purged, so it is automatically retried at next sync. Things like that.

4 Likes
#7

My workaround is to delete the Fruux account on my XA2, and re-create it. Now everything seems to sync again. Not ideal of course…

#8

When it happens, could you follow these instructions:
https://sailfishos.org/wiki/CalDAV_and_CardDAV_Community_Contributions

Like that you can gather logs, post them here. I may correct the problem then. Because, even if my failures branch is accepted in a version later than 3.4.0, the failing events will not be synced and you may still miss an event that cannot be imported. Thus the importance to report issues for them to be corrected.

That being said, 3.4.0 should bring various improvements in term of bug corrections for CalDAV sync, in particular with respect to recurring events with exceptions, see https://git.sailfishos.org/mer-core/buteo-sync-plugin-caldav/commits/master and in particular this commit from Chris Adams or this one for servers not returning etags on put.

2 Likes
#9

I’ve discussed among other matters today with Chris Adams from Jolla on IRC about the possibility not to stop a sync process on error and to report these errors on a per event basis. Feel free to read the logs if you are interested:

https://irclogs.sailfishos.org/logs/%23sailfishos/%23sailfishos.2020-07-21.log.html

The result of the discussion is that he is interested with the approach. Of course other sailors like Pekka Vuorela or Joona Petrell may be interested to give their opinion too in the view of the amount of code change before any code review could be started.

2 Likes
#10

Gave it a quick read. Thanks a lot for getting started on this so quickly.

So it seems when put into context the problem has some more dimensions. We have the push issue, but a similar issue can arise on pull as well. And then there’s the whole question of how to handle the various error cases in the UI.

Given that there seems to be quite some technical complexity involved, I’d advocate decoupling the sync changes from the UI questions. The whole thing could be handled in two stages:

First make the sync process more robust, without worrying about user notifications. Currently the user isn’t notified of any issues anyways, so this would already be a major improvement on its own.

Then the sync fixes can be rolled out much more quickly, while the UI handling can be discussed separately with the relevant people. Sounds to me like there are some error cases that raise UX/usability/design questions and the necessary behaviour penetrates layers that involve more people.

That’s just my 2 cents without actually knowing much about the architecture. But I’d like to avoid complex UI questions blocking the sync improvements from going forward.

Anyways, thanks again for your work so far!

#11

In fact, I was working on this for a while already. Your topic was an opportunity to speak about it.

Don’t worry, that’s how I will advocate the changes. Currently, all commits are in the same branch, but well separated. The one enabling UI notifications are on top of those allowing to continue on errors. It’s easier for me to test and use it daily. Depending on how design discussions will evolve (UI-wise, but also on code design to report error to the user), I will separate this branch into two merge requests and try to ensure that the pure CalDAV error handling will enter the version after 3.4.0.

By the way, it’s difficult at the moment to create packages to adventurous users who would like to try, because the commits are based on various changes in the underlying layers (both in mKCal and KCalCore) and I don’t really want to rebase them on top of the version available in 3.3.0. But as soon as 3.4.0 is available for EA users, I will package the pure CalDAV part, so it can be tested and I could get feedback.

2 Likes