Hello!

Another test failure. This time, the SyncEvolution test suite simulates
the following situation:
      * Client has one added item.
      * Two-way sync gets as far as the client sending the <Add> for
        that item.
      * Server processes that message, adding the item, and sends back a
        reply.
      * Transport "fails" and reply is lost, resending also doesn't
        work, so client suspends.
      * So does the server, after a timeout.
      * Next session resumes.
      * Client sends that item again (because it cannot know whether the
        server has it).
      * Server adds the item *again*, leading to a duplicate.

Note that the client is no longer using <Replace>, as in older versions.
Instead it uses <Add>. I think the expectation is that the server
recognizes that it already has the item based on the client's item ID,
but that doesn't seem to work.

The item has ID 828 on the client. Here are the relevant log entries
from the session where the server duplicates the item:


[2010-02-26 15:30:07.425] 'MakeAdminReady' - Making Admin Data ready to
check sync anchors, localDB=addressbook,
remoteDB=./file_vcard30 [--][++] [->end] [->enclosing]
      * [2010-02-26 15:30:07.425] Rebuilding - initscript,
        ctx=0x1B07530, VarDefs:
      * [2010-02-26 15:30:07.425] 0: string itemdata
      * [2010-02-26 15:30:07.425] Rebuilding - afterreadscript,
        ctx=0x1B07530, VarDefs:
      * [2010-02-26 15:30:07.425] 0: string itemdata
      * [2010-02-26 15:30:07.425] Rebuilding - beforewritescript,
        ctx=0x1B07530, VarDefs:
      * [2010-02-26 15:30:07.425] 0: string itemdata
      * [2010-02-26 15:30:07.425] PrepareLocals - beforewritescript,
        ctx=0x1B07530, VarDefs:
      * [2010-02-26 15:30:07.425] 0: string itemdata
      * [2010-02-26 15:30:07.425] 'addressbook' dev='client-test-2'
        usr='' err=0
      * [2010-02-26 15:30:07.425] 'addressbook' dev='client-test-2'
        usr='' err=0
      * [2010-02-26 15:30:07.425] LoadAdminData 'addressbook'
        './file_vcard30', res=0
      * [2010-02-26 15:30:07.425] ReadNextMapItem 7FFF8C3CEB00 first=yes
        res=1
      * ....
      * [2010-02-26 15:30:07.426] read map entry (type=normal):
        localid='1362', remoteid='828', mapflags=0x0
      * [2010-02-26 15:30:07.426] ReadNextMapItem 7FFF8C3CEB00 first=no
        res=0
      * [2010-02-26 15:30:07.426] First time sync or config changed
        since last sync -> remote should see our devinf


[2010-02-26 15:30:07.476] 'GetItems' - Read items from DB
implementation, datastore=addressbook [--][++] [->end] [->enclosing]
      * [2010-02-26 15:30:07.476] Resuming and found item not marked for
        resume -> ignore for delete checking
      * ...
      * [2010-02-26 15:30:07.476] Item localID='1362' already has map
        entry: remoteid='828', mapflags=0x0, changed=0, deleted=0,
        added=0, markforresume=0, savedmark=0


2010-02-26 15:30:07.477] 'processCmd' - Processing incoming command,
Cmd=Add, IncomingMsgID=2, CmdID=5 [--][++] [->end] [->enclosing]
      * [2010-02-26 15:30:07.477] command started processing
      * [2010-02-26 15:30:07.477] Created command 'Status' (outgoing)
      * [2010-02-26 15:30:07.477] Item (syncop: add) started processing,
        remoteID='828', localID=''
      * [2010-02-26 15:30:07.477] Remote sent add-operation:
      * [2010-02-26 15:30:07.477] - Source: remoteID ='828',
        remoteName=''
      * [2010-02-26 15:30:07.477] - Target: localID ='', remoteName=''
      * [2010-02-26 15:30:07.477] Explicit type 'text/vcard' specified
        in command or item meta
      * [2010-02-26 15:30:07.477] Version '3.0' obtained from item data
      * ...
      * [2010-02-26 15:30:07.486] InsertItemAsKey res=0
  * [2010-02-26 15:30:07.486] ModifyMap called: aEntryType=normal,
    aLocalID='1363, aRemoteid='828', aMapflags=0x0, aDelete=0
  * [2010-02-26 15:30:07.486] - found no matching entry for localID
    '1363' - creating new one, added=true
  * [2010-02-26 15:30:07.486] - cleanup: removing same remoteID from
    other entry with localid='1362', mapflags=0x0, changed=0, deleted=0,
    added=0, markforresume=0, savedmark=0
  * [2010-02-26 15:30:07.487] - Operation add performed (regular),
    Remote ID=828 Local ID=1363, status=201

So it seems that the engine does check for the remote ID, but only after
having already added the item again.

Any comments?

Again, for the records, this can be reproduced with:
CLIENT_TEST_SERVER=syncevolution CLIENT_TEST_RETRY=t
CLIENT_TEST_RESEND=t CLIENT_TEST_SUSPEND=t CLIENT_TEST_INTERRUPT_AT=3
CLIENT_TEST_EVOLUTION_PREFIX=file:///tmp/test_ ./client-test
Client::Sync::file_vcard30::Retry::testInterruptResumeClientAdd


-- 
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.



_______________________________________________
os-libsynthesis mailing list
os-libsynthesis@synthesis.ch
http://lists.synthesis.ch/mailman/listinfo/os-libsynthesis

Reply via email to