Bug 57004

/home/nightly/.cache/syncevolution/memotoo__1@client_+test_+memotoo_+1-2012-11-12-02-43-a
+---------------|-----------------------|-----------------------|-CON-+
|               |         LOCAL         |        REMOTE         | FLI |
|        Source | NEW | MOD | DEL | ERR | NEW | MOD | DEL | ERR | CTS |
+---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+
|     eds_event |  0  |  0  |  0  |  0  |  0  |  0  |  0  |  0  |  0  |
|     two-way, 0 KB sent by client, 0 KB received                     |
|     item(s) in database backup: 1 before sync, 1 after it           |
+---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+
|          start Mon Nov 12 02:43:53 2012, duration 0:02min           |
|               synchronization completed successfully                |
+---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+

/home/nightly/.cache/syncevolution/memotoo__1@client_+test_+memotoo_+1-2012-11-12-02-44
+---------------|-----------------------|-----------------------|-CON-+
|               |         LOCAL         |        REMOTE         | FLI |
|        Source | NEW | MOD | DEL | ERR | NEW | MOD | DEL | ERR | CTS |
+---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+
|   eds_contact |  0  |  0  |  0  |  0  |  0  |  0  |  0  |  0  |  0  |
|   slow, 0 KB sent by client, 0 KB received                          |
|   unexpected slow sync (local, status 22000)                        |
+---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+
|     eds_event |  0  |  0  |  0  |  0  |  0  |  0  |  0  |  0  |  0  |
|     two-way, 0 KB sent by client, 0 KB received                     |
|     item(s) in database backup: 1 before sync, 1 after it           |
|     aborted on behalf of user (local, status 20017)                 |
+---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+
|          start Mon Nov 12 02:44:01 2012, duration 0:02min           |
|           aborted on behalf of user (local, status 20017)           |
+---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+
First ERROR encountered: unexpected slow sync (local, status 22000)

/home/nightly/.cache/syncevolution/memotoo__1@client_+test_+memotoo_+1-2012-11-12-02-44-a
+---------------|-----------------------|-----------------------|-CON-+
|               |         LOCAL         |        REMOTE         | FLI |
|        Source | NEW | MOD | DEL | ERR | NEW | MOD | DEL | ERR | CTS |
+---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+
|     eds_event |  0  |  0  |  0  |  0  |  0  |  0  |  0  |  0  |  0  |
|     slow, 0 KB sent by client, 0 KB received                        |
|     unexpected slow sync (local, status 22000)                      |
+---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+
|          start Mon Nov 12 02:44:10 2012, duration 0:01min           |
|             unexpected slow sync (local, status 22000)              |
+---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+
First ERROR encountered: unexpected slow sync (local, status 22000)

The problem here, with Memotoo, was on the server side.

The client correctly aborts the session 2012-11-12-02-44 and in the 2012-11-12-02-44-a session sends (almost) the same Alert as before.

First session:

* [2012-11-12 02:44:01.869] (Saved) Last Local Client Anchor='20121112T024353Z', (generated) Next Local
       Client Anchor='20121112T024401Z' (sent to server as <last>/<next> in <alert>)
     * [2012-11-12 02:44:01.869] Created command 'Alert' (outgoing)
     * [2012-11-12 02:44:01.869] eds_event: ALERTING server for normal Sync

Second session:

* [2012-11-12 02:44:10.840] (Saved) Last Local Client Anchor='20121112T024353Z', (generated) Next Local
       Client Anchor='20121112T024410Z' (sent to server as <last>/<next> in <alert>)
     * [2012-11-12 02:44:10.840] Alerting resume of last sync session (original alert code = 200)
     * [2012-11-12 02:44:10.840] Created command 'Alert' (outgoing)
     * [2012-11-12 02:44:10.840] eds_event: ALERTING server for RESUMED normal Sync

Note that the anchor hasn't changed. What has changed is that the client considers this resuming the aborted normal two-way sync (<Data>225</Data> in the Alert).

The server then rejects that mode and forces a slow sync:
[2012-11-12 02:44:11.937] Alerted (code=201) for Resumed two-way Slow Sync

Either the server doesn't support resuming a sync, or it did not handle the suspending of the aborted session correctly.

On a related note, the "eds_event" gets prepared (including pre and post data dumps) completely in the sync where "eds_contact" causes the sync to be aborted.

I'm not sure how to handle this. Several options exist:
- avoid the "resume normal sync" in favor of doing a regular "normal sync"
  if the sync gets aborted early;
  not sure whether this is possible here, because the local store was
  initialized and may have changed state
- continue the sync with just the stores which are in an okay state;
  I suspect that SyncML is not prepared to handle this, and even if it is,
  servers probably were never used and thus tested for this
- only sync one source at a time at the SyncML level

I think the right solution is the third one. It makes each SyncML session a lot easier. The downside is that some servers might impose a limit on the number of sessions. Not combining multiple sources into a single session increases the number of required sessions.

The original report was for Funambol. When I tried to test with Funambol today, I couldn't connect and thus tested with Memotoo instead.

-- GitLab Migration Automatic Message --

This bug has been migrated to freedesktop.org's GitLab instance and has been closed from further activity.

You can subscribe and participate further through the new bug through this link to our GitLab instance: https://gitlab.freedesktop.org/SyncEvolution/libsynthesis/issues/4.