[SyncEvolution] syncevolution debug help needed

[Patrick Ohly]

On Fri, 2016-07-29 at 21:27 +0200, deloptes wrote:
> Patrick Ohly wrote:
> 
> > On Thu, 2016-07-28 at 19:22 +0200, deloptes wrote:
> >> Hi,
> >> from time to time I'm getting in following situation.
> >> Do you have some hint how I can understand what is wrong here. It works
> >> fine, but at once I start getting those messages.
> >>
> >>  The following output was
> >> created with SYNCEVOLUTION_DEBUG=3 syncevolution nokia_N9 calendar+todo
> > 
> > The only unusual message that I noticed is:
> > 
> >> [2016-07-28 18:49:04.473] to-be-added item already exists -> trying
> >> [replace
> >> (=conflict resolved by client winning)
> >> [2016-07-28 18:49:04.473] TCustomImplDS::implProcessItem 0x27e1620
> >> [starting,
> >> SyncOp=replace, RemoteID='496', LocalID=''
> >> [2016-07-28 18:49:04.473] Executing Script 'beforewritescript'
> >> [2016-07-28 18:49:04.473] todo: updating "Juli call ptotesi gel"
> >> [2016-07-28 18:49:04.473] todo: Item delete: (
> >> 00287b7f-207e-476b-96ad-6d0758d563e1 )
> >> [2016-07-28 18:49:04.764] todo: Item saved: (
> >> 00287b7f-207e-476b-96ad-6d0758d563e1 )
> >> [2016-07-28 18:49:04.764] todo: Item (
> >> 00287b7f-207e-476b-96ad-6d0758d563e1 : 20160704T075430Z ) done.
> >> [2016-07-28 18:49:04.764] todo:
> >> [aID=(00287b7f-207e-476b-96ad-6d0758d563e1,)
> >> res=208
> >> [2016-07-28 18:49:04.764] - Operation replace failed with SyncML
> >> [status=208
> > 
> > I'm not entirely sure why it is marked as "failed" - does that really
> > break syncing?
> > 
> > DB_DataReplaced = 208 = ITEM_REPLACED in SyncEvolution.
> > 
> > I'm not exactly sure where the "Item delete" and "Item saved" messages
> > come from. Is that perhaps from your backend?
> > 
> 
> Yes it comes from the backend. Unfortunately I am not exactly sure if I have
> to propagate the change immediately as it has a kind of cache, but I think
> it does not work properly, so I will save immediately
> 
> 
> > The underlying problem here is that calendar items are supposed to be
> > unique, based on their UID. That is a semantic that needs to be enforced
> > in calendar applications. However, some clients (in particular older,
> > vCalendar 1.0 based phones) do not support the same semantic. What could
> > happen is that (for whatever reason - that's often what needs to be
> > investigated) a phone asks to *add* an item with a UID that already is
> > in use by an existing item. In that case, the existing item needs to be
> > updated.
> 
> This is also my understanding and the way I think I implemented it

Looking again and based on your code I've come to a slightly different
conclusion: in the log above, the libsynthesis engine itself already
detects that it needs to update an item. From the libsynthesis code:

                // in normal sync in the server case, this can happen when a previous session
                // was aborted (and already applied adds not rolled back)
                // --> reprocess it as a replace
                PDEBUGPRINTFX(DBG_DATA,("to-be-added item already exists -> trying replace (=conflict resolved by client winning)"));


> I have implemented this logic in insertItem the following way
> 
>         ...
>         InsertItemResultState state = ITEM_OKAY;
>         ...
> 
>         KCal::Incidence *oldinc = calendarPtr->incidence(uid);
>         if (oldinc) {
>                 if ( ! calendarPtr->deleteIncidence(oldinc))
>                         Exception::throwError(SE_HERE, "internal error, unable to delete item
> from calendar");
> 
> ---> I add now these 2 lines here
>                 if ( ! calendarPtr->save() ) // It looks like we have to propagate the
> change immediately
>                         Exception::throwError(SE_HERE, "internal error, unable to save
> calendar");
> ---> 
>                 state = ITEM_REPLACED;
>                 SE_LOG_DEBUG(getDisplayName(), "Item delete: ( %s )", uid.latin
> () );
>         }
>         ...
>         ...
> 
> This was one of the last doubts I have at this stage, but I am still not
> confident. Could be that it needs improvement.

Is the full code available somewhere?

In the situation from the log file, your insertItem is called with a
non-empty uid and thus needs update the corresponding item. Returning
ITEM_REPLACED for an update operation is unexpected and thus leads to
the sync error that you encountered.

The code that you are showing shouldn't be used in this case, or if it
is used (for example, because "update" always equals "delete + add"), it
should return ITEM_OKAY.

-- 
Best Regards, Patrick Ohly

The content of this message is my personal opinion only and although
I am an employee of Intel, the statements I make here in no way
represent Intel's position on the issue, nor am I authorized to speak
on behalf of Intel on this matter.