[DEBUG 00:00:00] *** starting Client::Sync::eds_contact::testManyDeletes *** [DEBUG 00:00:00] ClientTest.cpp:4620: starting deleteAll() [DEBUG 00:00:00] ClientTest.cpp:3116: starting allSourcesDeleteAll() [DEBUG 00:00:00] ClientTest.cpp:6491: starting source_pair.second->deleteAll(source_pair.second->createSourceA) [DEBUG 00:00:00] ClientTest.cpp:802: starting CPPUNIT_ASSERT(createSource.createSource) [DEBUG 00:00:00] ClientTest.cpp:802: ending CPPUNIT_ASSERT(createSource.createSource) [DEBUG 00:00:00] ClientTest.cpp:807: starting source.reset(createSource()) [DEBUG 00:00:00] instantiating testing source eds_contact in config target-config@client-test-edsdav, with tracking name _1_A [DEBUG 00:00:00] overriding testing source eds_contact properties with the ones from config edsdav_1 = /data/runtests/work/testing-amd64/home/edsdav/config/syncevolution/client-test-edsdav-1/peers/edsdav_1 [DEBUG 00:00:00] sync = two-way (set) [DEBUG 00:00:00] uri = addressbook (set) [DEBUG 00:00:00] backend = Evolution Address Book (set) [DEBUG 00:00:00] syncFormat = (default) [DEBUG 00:00:00] forceSyncFormat = 0 (default) [DEBUG 00:00:00] database = Test_eds_contact_1 (set) [DEBUG 00:00:00] databaseFormat = (default) [DEBUG 00:00:00] databaseUser = (default) [DEBUG 00:00:00] databasePassword = (default) [DEBUG 00:00:02] instantiating testing source eds_contact in config target-config@client-test-edsdav, with tracking name _1_A [DEBUG 00:00:02] overriding testing source eds_contact properties with the ones from config edsdav_1 = /data/runtests/work/testing-amd64/home/edsdav/config/syncevolution/client-test-edsdav-1/peers/edsdav_1 [DEBUG 00:00:02] sync = two-way (set) [DEBUG 00:00:02] uri = addressbook (set) [DEBUG 00:00:02] backend = Evolution Address Book (set) [DEBUG 00:00:02] syncFormat = (default) [DEBUG 00:00:02] forceSyncFormat = 0 (default) [DEBUG 00:00:02] database = Test_eds_contact_1 (set) [DEBUG 00:00:02] databaseFormat = (default) [DEBUG 00:00:02] databaseUser = (default) [DEBUG 00:00:02] databasePassword = (default) [DEBUG 00:00:02] ClientTest.cpp:424: starting CPPUNIT_ASSERT(get()) [DEBUG 00:00:02] ClientTest.cpp:424: ending CPPUNIT_ASSERT(get()) [DEBUG 00:00:02] ClientTest.cpp:425: starting CPPUNIT_ASSERT(!m_active) [DEBUG 00:00:02] ClientTest.cpp:425: ending CPPUNIT_ASSERT(!m_active) [DEBUG 00:00:02] ClientTest.cpp:431: starting get()->open() [DEBUG 00:00:02] ClientTest.cpp:431: ending get()->open() [DEBUG 00:00:02] eds_contact: slow sync or testing, do full item scan to detect changes [DEBUG 00:00:02] ClientTest.cpp:807: ending source.reset(createSource()) [DEBUG 00:00:02] ClientTest.cpp:807: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:00:02] ClientTest.cpp:807: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:00:02] ClientTest.cpp:810: starting source->removeAllItems() [DEBUG 00:00:02] ClientTest.cpp:810: ending source->removeAllItems() [DEBUG 00:00:02] ClientTest.cpp:810: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:00:02] ClientTest.cpp:810: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:00:02] ClientTest.cpp:811: starting source.reset() [DEBUG 00:00:02] ClientTest.cpp:454: starting CPPUNIT_ASSERT(get()) [DEBUG 00:00:02] ClientTest.cpp:454: ending CPPUNIT_ASSERT(get()) [DEBUG 00:00:02] ClientTest.cpp:455: starting CPPUNIT_ASSERT(m_active) [DEBUG 00:00:02] ClientTest.cpp:455: ending CPPUNIT_ASSERT(m_active) [DEBUG 00:00:02] ClientTest.cpp:458: starting get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:00:03] ClientTest.cpp:458: ending get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:00:03] ClientTest.cpp:461: starting anchor = get()->endSync(true) [DEBUG 00:00:03] ClientTest.cpp:461: ending anchor = get()->endSync(true) [DEBUG 00:00:03] ClientTest.cpp:463: starting get()->close() [DEBUG 00:00:03] ClientTest.cpp:463: ending get()->close() [DEBUG 00:00:03] ClientTest.cpp:811: ending source.reset() [DEBUG 00:00:03] ClientTest.cpp:814: starting source.reset(createSource()) [DEBUG 00:00:03] instantiating testing source eds_contact in config target-config@client-test-edsdav, with tracking name _1_A [DEBUG 00:00:03] overriding testing source eds_contact properties with the ones from config edsdav_1 = /data/runtests/work/testing-amd64/home/edsdav/config/syncevolution/client-test-edsdav-1/peers/edsdav_1 [DEBUG 00:00:03] sync = two-way (set) [DEBUG 00:00:03] uri = addressbook (set) [DEBUG 00:00:03] backend = Evolution Address Book (set) [DEBUG 00:00:03] syncFormat = (default) [DEBUG 00:00:03] forceSyncFormat = 0 (default) [DEBUG 00:00:03] database = Test_eds_contact_1 (set) [DEBUG 00:00:03] databaseFormat = (default) [DEBUG 00:00:03] databaseUser = (default) [DEBUG 00:00:03] databasePassword = (default) [DEBUG 00:00:03] ClientTest.cpp:424: starting CPPUNIT_ASSERT(get()) [DEBUG 00:00:03] ClientTest.cpp:424: ending CPPUNIT_ASSERT(get()) [DEBUG 00:00:03] ClientTest.cpp:425: starting CPPUNIT_ASSERT(!m_active) [DEBUG 00:00:03] ClientTest.cpp:425: ending CPPUNIT_ASSERT(!m_active) [DEBUG 00:00:03] ClientTest.cpp:431: starting get()->open() [DEBUG 00:00:03] ClientTest.cpp:431: ending get()->open() [DEBUG 00:00:04] eds_contact: using full item scan to detect changes [DEBUG 00:00:04] ClientTest.cpp:814: ending source.reset(createSource()) [DEBUG 00:00:04] ClientTest.cpp:814: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:00:04] ClientTest.cpp:814: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:00:04] ClientTest.cpp:818: starting CPPUNIT_ASSERT_MESSAGE(("should be empty now"), ((countItems(source.get()) == 0))) [DEBUG 00:00:04] ClientTest.cpp:818: ending CPPUNIT_ASSERT_MESSAGE(("should be empty now"), ((countItems(source.get()) == 0))) [DEBUG 00:00:04] ClientTest.cpp:818: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:00:04] ClientTest.cpp:818: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:00:04] ClientTest.cpp:819: starting CPPUNIT_ASSERT_EQUAL((0),(countNewItems(source.get()))) [DEBUG 00:00:04] ClientTest.cpp:819: ending CPPUNIT_ASSERT_EQUAL((0),(countNewItems(source.get()))) [DEBUG 00:00:04] ClientTest.cpp:820: starting CPPUNIT_ASSERT_EQUAL((0),(countUpdatedItems(source.get()))) [DEBUG 00:00:04] ClientTest.cpp:820: ending CPPUNIT_ASSERT_EQUAL((0),(countUpdatedItems(source.get()))) [DEBUG 00:00:04] ClientTest.cpp:821: starting CPPUNIT_ASSERT_EQUAL((0),(countDeletedItems(source.get()))) [DEBUG 00:00:04] ClientTest.cpp:821: ending CPPUNIT_ASSERT_EQUAL((0),(countDeletedItems(source.get()))) [DEBUG 00:00:04] ClientTest.cpp:391: starting reset(__null) [DEBUG 00:00:04] ClientTest.cpp:454: starting CPPUNIT_ASSERT(get()) [DEBUG 00:00:04] ClientTest.cpp:454: ending CPPUNIT_ASSERT(get()) [DEBUG 00:00:04] ClientTest.cpp:455: starting CPPUNIT_ASSERT(m_active) [DEBUG 00:00:04] ClientTest.cpp:455: ending CPPUNIT_ASSERT(m_active) [DEBUG 00:00:04] ClientTest.cpp:458: starting get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:00:04] ClientTest.cpp:458: ending get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:00:04] ClientTest.cpp:461: starting anchor = get()->endSync(true) [DEBUG 00:00:04] ClientTest.cpp:461: ending anchor = get()->endSync(true) [DEBUG 00:00:04] ClientTest.cpp:463: starting get()->close() [DEBUG 00:00:04] ClientTest.cpp:463: ending get()->close() [DEBUG 00:00:04] ClientTest.cpp:391: ending reset(__null) [DEBUG 00:00:04] ClientTest.cpp:6491: ending source_pair.second->deleteAll(source_pair.second->createSourceA) [DEBUG 00:00:04] ClientTest.cpp:3116: ending allSourcesDeleteAll() [DEBUG 00:00:04] ClientTest.cpp:3117: starting doSync(logPrefix, options) [DEBUG 00:00:04] 1. starting Client_Sync_eds_contact_testManyDeletes.deleteall.refreshserver.client.A with sync mode refresh-from-client [DEBUG 00:00:04] ClientTest.cpp:6460: starting res = client.doSync(sourceArray, logname, options) [DEBUG 00:00:04] log path -> /data/runtests/work/testing-amd64/home/edsdav/cache/syncevolution, No such file or directory [DEBUG 00:00:04] log path -> Client_Sync_eds_contact_testManyDeletes.deleteall.refreshserver.client.A, No such file or directory [DEBUG 00:00:04] log path -> Client_Sync_eds_contact_testManyDeletes.deleteall.refreshserver.client.A, No such file or directory [DEBUG 00:00:04] checking log dir Client_Sync_eds_contact_testManyDeletes.deleteall.refreshserver.client.A [DEBUG 00:00:04] logfile: Client_Sync_eds_contact_testManyDeletes.deleteall.refreshserver.client.A/syncevolution-log.html [DEVELOPER 00:00:07] SyncML server account: user01 [DEVELOPER 00:00:07] client: SyncEvolution 1.5.3 for workstation [DEVELOPER 00:00:07] device ID: client-edsdav_1 [DEVELOPER 00:00:07] [DEVELOPER 00:00:07] [INFO 00:00:07] addressbook: inactive [INFO 00:00:07] calendar: inactive [INFO 00:00:07] calendar+todo: inactive [INFO 00:00:07] eas_contact: inactive [INFO 00:00:07] eas_event: inactive [INFO 00:00:07] eas_memo: inactive [INFO 00:00:07] eas_task: inactive [INFO 00:00:07] eds_event: inactive [INFO 00:00:07] eds_memo: inactive [INFO 00:00:07] eds_task: inactive [INFO 00:00:07] file_calendar+todo: inactive [INFO 00:00:07] file_contact: inactive [INFO 00:00:07] file_event: inactive [INFO 00:00:07] file_task: inactive [INFO 00:00:07] kde_contact: inactive [INFO 00:00:07] kde_event: inactive [INFO 00:00:07] kde_memo: inactive [INFO 00:00:07] kde_task: inactive [INFO 00:00:07] memo: inactive [INFO 00:00:07] todo: inactive [DEBUG 00:00:07] checking password property 'password' in config 'edsdav_1@client-test-edsdav-1' with user identity 'user01' [DEBUG 00:00:07] loading password from keyring with key user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:00:07] not using KWallet [DEBUG 00:00:08] sync password for edsdav_1@client-test-edsdav-1: loaded password from GNOME keyring using user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:00:08] checking password property 'databasePassword' in datastore 'eds_contact' of config 'edsdav_1@client-test-edsdav-1' with user identity '' [DEBUG 00:00:08] sync is starting, catch signals [DEBUG 00:00:08] SuspendFlags: (re)activating, currently inactive [DEBUG 00:00:08] SuspendFlags: activating signal handler(s) with fds 38->37 [DEBUG 00:00:08] SuspendFlags: catch signal 15 [DEBUG 00:00:08] ready to sync [DEBUG 00:00:08] CreateContext SyncEvolution//eds_contact => 0 [DEBUG 00:00:08] Module_Version = 01090100 [DEBUG 00:00:08] Module_Capabilities: [DEBUG 00:00:08] PLATFORM:Linux [DEBUG 00:00:08] DLL:true [DEBUG 00:00:08] MINVERSION:V1.0.6.0 [DEBUG 00:00:08] MANUFACTURER:SyncEvolution [DEBUG 00:00:08] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:00:08] plugin_datastore_str:no [DEBUG 00:00:08] plugin_datastore_key:yes [DEBUG 00:00:08] ITEM_AS_KEY:yes [DEBUG 00:00:08] plugin_datablob:no [DEBUG 00:00:08] eds_contact: Module_PluginParams [DEBUG 00:00:08] eds_contact: Engine=01090100 [DEBUG 00:00:08] eds_contact: [DEBUG 00:00:08] Module_Capabilities: [DEBUG 00:00:08] PLATFORM:Linux [DEBUG 00:00:08] DLL:true [DEBUG 00:00:08] MINVERSION:V1.0.6.0 [DEBUG 00:00:08] MANUFACTURER:SyncEvolution [DEBUG 00:00:08] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:00:08] plugin_datastore_str:no [DEBUG 00:00:08] plugin_datastore_key:yes [DEBUG 00:00:08] ITEM_AS_KEY:yes [DEBUG 00:00:08] plugin_datablob:no [DEBUG 00:00:08] copying syncURL, username, password to Synthesis engine [DEBUG 00:00:08] using plain username/password for user01 [DEBUG 00:00:09] eds_contact: total number of items received 0 [INFO 00:00:27] eds_contact: starting first time sync from client (peer is server) [DEBUG 00:00:27] reading: set read-ahead based on sync mode refresh-from-local [DEBUG 00:00:27] eds_contact: reading: set order 'all', 0 luids [DEBUG 00:00:27] eds_contact: 'eds_contact' dev='anydevice' usr='singleuser' err=0 [DEBUG 00:00:27] eds_contact: FilterSupport staticfilter: [DEBUG 00:00:27] eds_contact: dynamicfilter: [DEBUG 00:00:27] eds_contact: invisiblefilter: [DEBUG 00:00:27] eds_contact: ContextSupport ReadNextItem:allfields [DEBUG 00:00:27] eds_contact: [DEBUG 00:00:27] eds_contact: slow sync or testing, do full item scan to detect changes [DEBUG 00:00:27] eds_contact: StartDataRead last='' resume='' res=0 [DEBUG 00:00:27] eds_contact: ReadNextItemAsKey aStatus=0 aID=((null),(null)) res=0 [DEBUG 00:00:27] eds_contact: EndDataRead res=0 [DEBUG 00:00:27] eds_contact: StartDataWrite [DEBUG 00:00:27] eds_contact: total number of items received 0 [INFO 00:00:29] eds_contact: started [DEBUG 00:00:29] eds_contact: total number of items received 0 [DEBUG 00:00:30] eds_contact: EndDataWrite COMMIT '1' res=0 [DEBUG 00:00:30] eds_contact: DeleteContext [INFO 00:00:30] eds_contact: first time sync done successfully [DEBUG 00:00:30] closing session [DEBUG 00:00:30] session closed [DEBUG 00:00:30] SuspendFlags: deactivating fds 38->37 [DEBUG 00:00:30] SuspendFlags: close m_receiverFD 37 [DEBUG 00:00:30] SuspendFlags: close m_senderFD 38 [DEBUG 00:00:30] SuspendFlags: done with deactivation [DEBUG 00:00:30] Module_DeleteContext eds_contact [INFO 00:00:30] sync report: [INFO 00:00:30] +---------------|-----------------------|-----------------------|-CON-+ [INFO 00:00:30] | | LOCAL | REMOTE | FLI | [INFO 00:00:30] | Source | NEW | MOD | DEL | ERR | NEW | MOD | DEL | ERR | CTS | [INFO 00:00:30] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:00:30] | eds_contact | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | 0 | [INFO 00:00:30] | refresh-from-local, 0 KB sent by client, 0 KB received | [INFO 00:00:30] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:00:30] | start Fri Jan 5 19:00:19 2018, duration 0:26min | [INFO 00:00:30] | synchronization completed successfully | [INFO 00:00:30] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:00:30] ----------|--------CLIENT---------|--------SERVER---------| [INFO 00:00:30] | NEW | MOD | DEL | NEW | MOD | DEL | [INFO 00:00:30] ----------|-----------------------------------------------| [INFO 00:00:30] Expected | 0 | 0 | 0 | 0 | 0 | -1 | [INFO 00:00:30] Expected sync mode: refresh-from-local [INFO 00:00:30] Expected cycles: 1 [INFO 00:00:30] [DEBUG 00:00:30] ClientTest.cpp:8283: starting CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:00:30] ClientTest.cpp:8283: ending CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:00:30] ClientTest.cpp:8284: starting CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:00:30] ClientTest.cpp:8284: ending CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:00:30] Checking sync source eds_contact... [DEBUG 00:00:30] ClientTest.cpp:8293: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:00:30] ClientTest.cpp:8293: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:00:30] ClientTest.cpp:8305: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:00:30] ClientTest.cpp:8305: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:00:30] ClientTest.cpp:8308: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:00:30] ClientTest.cpp:8308: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:00:30] ClientTest.cpp:8319: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:00:30] ClientTest.cpp:8319: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:00:30] ClientTest.cpp:8322: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:00:30] ClientTest.cpp:8322: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:00:30] ClientTest.cpp:8328: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(clientAdded),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:30] ClientTest.cpp:8328: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(clientAdded),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:30] ClientTest.cpp:8334: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:30] ClientTest.cpp:8334: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:30] ClientTest.cpp:8340: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(clientDeleted),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:30] ClientTest.cpp:8340: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(clientDeleted),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:30] ClientTest.cpp:8347: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:30] ClientTest.cpp:8347: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:30] ClientTest.cpp:8353: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:30] ClientTest.cpp:8353: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:30] Done with checking sync report. [DEBUG 00:00:30] ClientTest.cpp:6460: ending res = client.doSync(sourceArray, logname, options) [DEBUG 00:00:30] ClientTest.cpp:6465: starting postSync(res, logname) [DEBUG 00:00:30] ClientTest.cpp:6465: ending postSync(res, logname) [DEBUG 00:00:30] ClientTest.cpp:3117: ending doSync(logPrefix, options) [DEBUG 00:00:30] ClientTest.cpp:4620: ending deleteAll() [DEBUG 00:00:30] ClientTest.cpp:4626: starting it->second->insertManyItems(it->second->createSourceA, 0, num_items, 100) [DEBUG 00:00:30] ClientTest.cpp:1005: starting CPPUNIT_ASSERT(!config.m_templateItem.empty()) [DEBUG 00:00:30] ClientTest.cpp:1005: ending CPPUNIT_ASSERT(!config.m_templateItem.empty()) [DEBUG 00:00:31] ClientTest.cpp:1009: starting source.reset(createSourceA()) [DEBUG 00:00:31] instantiating testing source eds_contact in config target-config@client-test-edsdav, with tracking name _1_A [DEBUG 00:00:31] overriding testing source eds_contact properties with the ones from config edsdav_1 = /data/runtests/work/testing-amd64/home/edsdav/config/syncevolution/client-test-edsdav-1/peers/edsdav_1 [DEBUG 00:00:31] sync = two-way (set) [DEBUG 00:00:31] uri = addressbook (set) [DEBUG 00:00:31] backend = Evolution Address Book (set) [DEBUG 00:00:31] syncFormat = (default) [DEBUG 00:00:31] forceSyncFormat = 0 (default) [DEBUG 00:00:31] database = Test_eds_contact_1 (set) [DEBUG 00:00:31] databaseFormat = (default) [DEBUG 00:00:31] databaseUser = (default) [DEBUG 00:00:31] databasePassword = (default) [DEBUG 00:00:31] ClientTest.cpp:424: starting CPPUNIT_ASSERT(get()) [DEBUG 00:00:31] ClientTest.cpp:424: ending CPPUNIT_ASSERT(get()) [DEBUG 00:00:31] ClientTest.cpp:425: starting CPPUNIT_ASSERT(!m_active) [DEBUG 00:00:31] ClientTest.cpp:425: ending CPPUNIT_ASSERT(!m_active) [DEBUG 00:00:31] ClientTest.cpp:431: starting get()->open() [DEBUG 00:00:31] ClientTest.cpp:431: ending get()->open() [DEBUG 00:00:31] eds_contact: using full item scan to detect changes [DEBUG 00:00:31] ClientTest.cpp:1009: ending source.reset(createSourceA()) [DEBUG 00:00:31] ClientTest.cpp:1009: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:00:31] ClientTest.cpp:1009: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:00:31] ClientTest.cpp:1010: starting CPPUNIT_ASSERT(startIndex > 1 || !countItems(source.get())) [DEBUG 00:00:31] ClientTest.cpp:1010: ending CPPUNIT_ASSERT(startIndex > 1 || !countItems(source.get())) [DEBUG 00:00:31] ClientTest.cpp:504: starting CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:504: ending CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:507: starting res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] eds_contact: add operation #0: queueing for batched add [DEBUG 00:00:31] eds_contact: batch add of 1 contacts starting [DEBUG 00:00:31] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:00:31] eds_contact: batch add of 1 contacts completed [DEBUG 00:00:31] eds_contact: add operation #0: completed: <<successfully>> [DEBUG 00:00:31] eds_contact: pending operations completed [DEBUG 00:00:31] eds_contact: add operation #0: checking operation: inserted [DEBUG 00:00:31] ClientTest.cpp:507: ending res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] ClientTest.cpp:507: starting CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:507: ending CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:508: starting CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:508: ending CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:504: starting CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:504: ending CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:507: starting res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] eds_contact: add operation #1: queueing for batched add [DEBUG 00:00:31] eds_contact: batch add of 1 contacts starting [DEBUG 00:00:31] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:00:31] eds_contact: batch add of 1 contacts completed [DEBUG 00:00:31] eds_contact: add operation #1: completed: <<successfully>> [DEBUG 00:00:31] eds_contact: pending operations completed [DEBUG 00:00:31] eds_contact: add operation #1: checking operation: inserted [DEBUG 00:00:31] ClientTest.cpp:507: ending res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] ClientTest.cpp:507: starting CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:507: ending CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:508: starting CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:508: ending CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:504: starting CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:504: ending CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:507: starting res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] eds_contact: add operation #2: queueing for batched add [DEBUG 00:00:31] eds_contact: batch add of 1 contacts starting [DEBUG 00:00:31] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:00:31] eds_contact: batch add of 1 contacts completed [DEBUG 00:00:31] eds_contact: add operation #2: completed: <<successfully>> [DEBUG 00:00:31] eds_contact: pending operations completed [DEBUG 00:00:31] eds_contact: add operation #2: checking operation: inserted [DEBUG 00:00:31] ClientTest.cpp:507: ending res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] ClientTest.cpp:507: starting CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:507: ending CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:508: starting CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:508: ending CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:504: starting CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:504: ending CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:507: starting res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] eds_contact: add operation #3: queueing for batched add [DEBUG 00:00:31] eds_contact: batch add of 1 contacts starting [DEBUG 00:00:31] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:00:31] eds_contact: batch add of 1 contacts completed [DEBUG 00:00:31] eds_contact: add operation #3: completed: <<successfully>> [DEBUG 00:00:31] eds_contact: pending operations completed [DEBUG 00:00:31] eds_contact: add operation #3: checking operation: inserted [DEBUG 00:00:31] ClientTest.cpp:507: ending res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] ClientTest.cpp:507: starting CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:507: ending CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:508: starting CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:508: ending CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:504: starting CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:504: ending CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:507: starting res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] eds_contact: add operation #4: queueing for batched add [DEBUG 00:00:31] eds_contact: batch add of 1 contacts starting [DEBUG 00:00:31] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:00:31] eds_contact: batch add of 1 contacts completed [DEBUG 00:00:31] eds_contact: add operation #4: completed: <<successfully>> [DEBUG 00:00:31] eds_contact: pending operations completed [DEBUG 00:00:31] eds_contact: add operation #4: checking operation: inserted [DEBUG 00:00:31] ClientTest.cpp:507: ending res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] ClientTest.cpp:507: starting CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:507: ending CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:508: starting CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:508: ending CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:504: starting CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:504: ending CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:507: starting res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] eds_contact: add operation #5: queueing for batched add [DEBUG 00:00:31] eds_contact: batch add of 1 contacts starting [DEBUG 00:00:31] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:00:31] eds_contact: batch add of 1 contacts completed [DEBUG 00:00:31] eds_contact: add operation #5: completed: <<successfully>> [DEBUG 00:00:31] eds_contact: pending operations completed [DEBUG 00:00:31] eds_contact: add operation #5: checking operation: inserted [DEBUG 00:00:31] ClientTest.cpp:507: ending res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] ClientTest.cpp:507: starting CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:507: ending CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:508: starting CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:508: ending CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:504: starting CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:504: ending CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:507: starting res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] eds_contact: add operation #6: queueing for batched add [DEBUG 00:00:31] eds_contact: batch add of 1 contacts starting [DEBUG 00:00:31] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:00:31] eds_contact: batch add of 1 contacts completed [DEBUG 00:00:31] eds_contact: add operation #6: completed: <<successfully>> [DEBUG 00:00:31] eds_contact: pending operations completed [DEBUG 00:00:31] eds_contact: add operation #6: checking operation: inserted [DEBUG 00:00:31] ClientTest.cpp:507: ending res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] ClientTest.cpp:507: starting CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:507: ending CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:508: starting CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:508: ending CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:504: starting CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:504: ending CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:507: starting res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] eds_contact: add operation #7: queueing for batched add [DEBUG 00:00:31] eds_contact: batch add of 1 contacts starting [DEBUG 00:00:31] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:00:31] eds_contact: batch add of 1 contacts completed [DEBUG 00:00:31] eds_contact: add operation #7: completed: <<successfully>> [DEBUG 00:00:31] eds_contact: pending operations completed [DEBUG 00:00:31] eds_contact: add operation #7: checking operation: inserted [DEBUG 00:00:31] ClientTest.cpp:507: ending res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] ClientTest.cpp:507: starting CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:507: ending CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:508: starting CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:508: ending CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:504: starting CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:504: ending CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:507: starting res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] eds_contact: add operation #8: queueing for batched add [DEBUG 00:00:31] eds_contact: batch add of 1 contacts starting [DEBUG 00:00:31] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:00:31] eds_contact: batch add of 1 contacts completed [DEBUG 00:00:31] eds_contact: add operation #8: completed: <<successfully>> [DEBUG 00:00:31] eds_contact: pending operations completed [DEBUG 00:00:31] eds_contact: add operation #8: checking operation: inserted [DEBUG 00:00:31] ClientTest.cpp:507: ending res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] ClientTest.cpp:507: starting CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:507: ending CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:508: starting CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:508: ending CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:504: starting CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:504: ending CPPUNIT_ASSERT(source) [DEBUG 00:00:31] ClientTest.cpp:507: starting res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] eds_contact: add operation #9: queueing for batched add [DEBUG 00:00:31] eds_contact: batch add of 1 contacts starting [DEBUG 00:00:31] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:00:31] eds_contact: batch add of 1 contacts completed [DEBUG 00:00:31] eds_contact: add operation #9: completed: <<successfully>> [DEBUG 00:00:31] eds_contact: pending operations completed [DEBUG 00:00:31] eds_contact: add operation #9: checking operation: inserted [DEBUG 00:00:31] ClientTest.cpp:507: ending res = source->insertItemRaw("", config.m_mangleItem(data, false, "")) [DEBUG 00:00:31] ClientTest.cpp:507: starting CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:507: ending CPPUNIT_ASSERT((source)) [DEBUG 00:00:31] ClientTest.cpp:508: starting CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:508: ending CPPUNIT_ASSERT(!res.m_luid.empty()) [DEBUG 00:00:31] ClientTest.cpp:391: starting reset(__null) [DEBUG 00:00:31] ClientTest.cpp:454: starting CPPUNIT_ASSERT(get()) [DEBUG 00:00:31] ClientTest.cpp:454: ending CPPUNIT_ASSERT(get()) [DEBUG 00:00:31] ClientTest.cpp:455: starting CPPUNIT_ASSERT(m_active) [DEBUG 00:00:31] ClientTest.cpp:455: ending CPPUNIT_ASSERT(m_active) [DEBUG 00:00:31] ClientTest.cpp:458: starting get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:00:32] ClientTest.cpp:458: ending get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:00:32] ClientTest.cpp:461: starting anchor = get()->endSync(true) [DEBUG 00:00:32] ClientTest.cpp:461: ending anchor = get()->endSync(true) [DEBUG 00:00:32] ClientTest.cpp:463: starting get()->close() [DEBUG 00:00:32] ClientTest.cpp:463: ending get()->close() [DEBUG 00:00:32] ClientTest.cpp:391: ending reset(__null) [DEBUG 00:00:32] ClientTest.cpp:4626: ending it->second->insertManyItems(it->second->createSourceA, 0, num_items, 100) [DEBUG 00:00:32] ClientTest.cpp:4630: starting doSync(logPrefix, options) [DEBUG 00:00:32] 2. starting Client_Sync_eds_contact_testManyDeletes.send.client.A with sync mode two-way [DEBUG 00:00:32] ClientTest.cpp:6460: starting res = client.doSync(sourceArray, logname, options) [DEBUG 00:00:32] log path -> /data/runtests/work/testing-amd64/home/edsdav/cache/syncevolution, No such file or directory [DEBUG 00:00:32] log path -> Client_Sync_eds_contact_testManyDeletes.send.client.A, No such file or directory [DEBUG 00:00:32] log path -> Client_Sync_eds_contact_testManyDeletes.send.client.A, No such file or directory [DEBUG 00:00:32] checking log dir Client_Sync_eds_contact_testManyDeletes.send.client.A [DEBUG 00:00:32] logfile: Client_Sync_eds_contact_testManyDeletes.send.client.A/syncevolution-log.html [DEVELOPER 00:00:34] SyncML server account: user01 [DEVELOPER 00:00:34] client: SyncEvolution 1.5.3 for workstation [DEVELOPER 00:00:34] device ID: client-edsdav_1 [DEVELOPER 00:00:34] [DEVELOPER 00:00:34] [INFO 00:00:34] addressbook: inactive [INFO 00:00:34] calendar: inactive [INFO 00:00:34] calendar+todo: inactive [INFO 00:00:34] eas_contact: inactive [INFO 00:00:34] eas_event: inactive [INFO 00:00:34] eas_memo: inactive [INFO 00:00:34] eas_task: inactive [INFO 00:00:34] eds_event: inactive [INFO 00:00:34] eds_memo: inactive [INFO 00:00:34] eds_task: inactive [INFO 00:00:34] file_calendar+todo: inactive [INFO 00:00:34] file_contact: inactive [INFO 00:00:34] file_event: inactive [INFO 00:00:34] file_task: inactive [INFO 00:00:34] kde_contact: inactive [INFO 00:00:34] kde_event: inactive [INFO 00:00:34] kde_memo: inactive [INFO 00:00:34] kde_task: inactive [INFO 00:00:34] memo: inactive [INFO 00:00:34] todo: inactive [DEBUG 00:00:34] checking password property 'password' in config 'edsdav_1@client-test-edsdav-1' with user identity 'user01' [DEBUG 00:00:34] loading password from keyring with key user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:00:34] not using KWallet [DEBUG 00:00:34] sync password for edsdav_1@client-test-edsdav-1: loaded password from GNOME keyring using user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:00:34] checking password property 'databasePassword' in datastore 'eds_contact' of config 'edsdav_1@client-test-edsdav-1' with user identity '' [DEBUG 00:00:34] sync is starting, catch signals [DEBUG 00:00:34] SuspendFlags: (re)activating, currently inactive [DEBUG 00:00:34] SuspendFlags: activating signal handler(s) with fds 38->37 [DEBUG 00:00:34] SuspendFlags: catch signal 15 [DEBUG 00:00:34] ready to sync [DEBUG 00:00:35] CreateContext SyncEvolution//eds_contact => 0 [DEBUG 00:00:35] Module_Version = 01090100 [DEBUG 00:00:35] Module_Capabilities: [DEBUG 00:00:35] PLATFORM:Linux [DEBUG 00:00:35] DLL:true [DEBUG 00:00:35] MINVERSION:V1.0.6.0 [DEBUG 00:00:35] MANUFACTURER:SyncEvolution [DEBUG 00:00:35] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:00:35] plugin_datastore_str:no [DEBUG 00:00:35] plugin_datastore_key:yes [DEBUG 00:00:35] ITEM_AS_KEY:yes [DEBUG 00:00:35] plugin_datablob:no [DEBUG 00:00:35] eds_contact: Module_PluginParams [DEBUG 00:00:35] eds_contact: Engine=01090100 [DEBUG 00:00:35] eds_contact: [DEBUG 00:00:35] Module_Capabilities: [DEBUG 00:00:35] PLATFORM:Linux [DEBUG 00:00:35] DLL:true [DEBUG 00:00:35] MINVERSION:V1.0.6.0 [DEBUG 00:00:35] MANUFACTURER:SyncEvolution [DEBUG 00:00:35] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:00:35] plugin_datastore_str:no [DEBUG 00:00:35] plugin_datastore_key:yes [DEBUG 00:00:35] ITEM_AS_KEY:yes [DEBUG 00:00:35] plugin_datablob:no [DEBUG 00:00:35] copying syncURL, username, password to Synthesis engine [DEBUG 00:00:35] using plain username/password for user01 [DEBUG 00:00:35] eds_contact: total number of items received 0 [INFO 00:00:51] eds_contact: starting normal sync, two-way (peer is server) [DEBUG 00:00:51] reading: set read-ahead based on sync mode two-way [DEBUG 00:00:51] eds_contact: reading: set order 'changed', 0 luids [DEBUG 00:00:51] eds_contact: 'eds_contact' dev='anydevice' usr='singleuser' err=0 [DEBUG 00:00:51] eds_contact: FilterSupport staticfilter: [DEBUG 00:00:51] eds_contact: dynamicfilter: [DEBUG 00:00:51] eds_contact: invisiblefilter: [DEBUG 00:00:51] eds_contact: using full item scan to detect changes [DEBUG 00:00:51] eds_contact: StartDataRead last='1' resume='1' res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=1 aID=(pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206,(null)) res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=1 aID=(pas-id-1724c66f21a14ffa33dab6aad01d623bcf38cf3f,(null)) res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=1 aID=(pas-id-2224ebc390e29d2c58dc0f55307e908cfb695af6,(null)) res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=1 aID=(pas-id-445ae45f630bcda9b6717a961a48f665c5a174a6,(null)) res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=1 aID=(pas-id-77131a5a1bc2321ef59cac200c3376f2f7e39376,(null)) res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=1 aID=(pas-id-ac218fa54de3f7bad05a25c8a054755e81c95714,(null)) res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=1 aID=(pas-id-b2e27c08fcc9673527090e1f399b59e4f876ed37,(null)) res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=1 aID=(pas-id-c9f94aa15be0ffe38240ca0edec043a9d2b40a02,(null)) res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=1 aID=(pas-id-e4da37f9a350fd6706d646445701381984dd6c7e,(null)) res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=1 aID=(pas-id-fbb979968dab877362e487166956e68299961db2,(null)) res=0 [DEBUG 00:00:51] eds_contact: ReadNextItemAsKey aStatus=0 aID=((null),(null)) res=0 [DEBUG 00:00:51] eds_contact: EndDataRead res=0 [DEBUG 00:00:51] eds_contact: reading: getting contact pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206 [DEBUG 00:00:51] eds_contact: reading: must read contact pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206 [DEBUG 00:00:51] eds_contact: reading: started contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:51] eds_contact: reading: active cache pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:51] eds_contact: reading: in running cache [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) finished: <<successful>> [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) got pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) got pas-id-e4da37f9a350fd6706d646445701381984dd6c7e [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) got pas-id-c9f94aa15be0ffe38240ca0edec043a9d2b40a02 [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) got pas-id-b2e27c08fcc9673527090e1f399b59e4f876ed37 [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) got pas-id-ac218fa54de3f7bad05a25c8a054755e81c95714 [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) got pas-id-77131a5a1bc2321ef59cac200c3376f2f7e39376 [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) got pas-id-445ae45f630bcda9b6717a961a48f665c5a174a6 [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) got pas-id-2224ebc390e29d2c58dc0f55307e908cfb695af6 [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) got pas-id-1724c66f21a14ffa33dab6aad01d623bcf38cf3f [DEBUG 00:00:51] eds_contact: reading: contact read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) got pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206 [DEBUG 00:00:51] eds_contact: reading: in cache, available [DEBUG 00:00:51] eds_contact: reading: continue after contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:51] eds_contact: reading: read pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206: <<okay>> [DEBUG 00:00:51] eds_contact: requested 1, retrieved 10 from DB in 1 queries, misses 0/1 (0%), stalls 1 [DEBUG 00:00:51] eds_contact: ReadItemAsKey aID=(pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206,) res=0 [DEBUG 00:00:52] eds_contact: reading: getting contact pas-id-1724c66f21a14ffa33dab6aad01d623bcf38cf3f [DEBUG 00:00:52] eds_contact: reading: active cache pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:52] eds_contact: reading: in loaded cache [DEBUG 00:00:52] eds_contact: reading: in cache, available [DEBUG 00:00:52] eds_contact: reading: continue after contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:52] eds_contact: reading: read pas-id-1724c66f21a14ffa33dab6aad01d623bcf38cf3f: <<okay>> [DEBUG 00:00:52] eds_contact: requested 2, retrieved 10 from DB in 1 queries, misses 0/2 (0%), stalls 1 [DEBUG 00:00:52] eds_contact: ReadItemAsKey aID=(pas-id-1724c66f21a14ffa33dab6aad01d623bcf38cf3f,) res=0 [DEBUG 00:00:52] eds_contact: reading: getting contact pas-id-2224ebc390e29d2c58dc0f55307e908cfb695af6 [DEBUG 00:00:52] eds_contact: reading: active cache pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:52] eds_contact: reading: in loaded cache [DEBUG 00:00:52] eds_contact: reading: in cache, available [DEBUG 00:00:52] eds_contact: reading: continue after contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:52] eds_contact: reading: read pas-id-2224ebc390e29d2c58dc0f55307e908cfb695af6: <<okay>> [DEBUG 00:00:52] eds_contact: requested 3, retrieved 10 from DB in 1 queries, misses 0/3 (0%), stalls 1 [DEBUG 00:00:52] eds_contact: ReadItemAsKey aID=(pas-id-2224ebc390e29d2c58dc0f55307e908cfb695af6,) res=0 [DEBUG 00:00:52] eds_contact: reading: getting contact pas-id-445ae45f630bcda9b6717a961a48f665c5a174a6 [DEBUG 00:00:52] eds_contact: reading: active cache pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:52] eds_contact: reading: in loaded cache [DEBUG 00:00:52] eds_contact: reading: in cache, available [DEBUG 00:00:52] eds_contact: reading: continue after contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:52] eds_contact: reading: read pas-id-445ae45f630bcda9b6717a961a48f665c5a174a6: <<okay>> [DEBUG 00:00:52] eds_contact: requested 4, retrieved 10 from DB in 1 queries, misses 0/4 (0%), stalls 1 [DEBUG 00:00:52] eds_contact: ReadItemAsKey aID=(pas-id-445ae45f630bcda9b6717a961a48f665c5a174a6,) res=0 [DEBUG 00:00:52] eds_contact: reading: getting contact pas-id-77131a5a1bc2321ef59cac200c3376f2f7e39376 [DEBUG 00:00:52] eds_contact: reading: active cache pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:52] eds_contact: reading: in loaded cache [DEBUG 00:00:52] eds_contact: reading: in cache, available [DEBUG 00:00:52] eds_contact: reading: continue after contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:52] eds_contact: reading: read pas-id-77131a5a1bc2321ef59cac200c3376f2f7e39376: <<okay>> [DEBUG 00:00:52] eds_contact: requested 5, retrieved 10 from DB in 1 queries, misses 0/5 (0%), stalls 1 [DEBUG 00:00:52] eds_contact: ReadItemAsKey aID=(pas-id-77131a5a1bc2321ef59cac200c3376f2f7e39376,) res=0 [DEBUG 00:00:52] eds_contact: reading: getting contact pas-id-ac218fa54de3f7bad05a25c8a054755e81c95714 [DEBUG 00:00:52] eds_contact: reading: active cache pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:52] eds_contact: reading: in loaded cache [DEBUG 00:00:52] eds_contact: reading: in cache, available [DEBUG 00:00:52] eds_contact: reading: continue after contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:52] eds_contact: reading: read pas-id-ac218fa54de3f7bad05a25c8a054755e81c95714: <<okay>> [DEBUG 00:00:52] eds_contact: requested 6, retrieved 10 from DB in 1 queries, misses 0/6 (0%), stalls 1 [DEBUG 00:00:52] eds_contact: ReadItemAsKey aID=(pas-id-ac218fa54de3f7bad05a25c8a054755e81c95714,) res=0 [DEBUG 00:00:52] eds_contact: reading: getting contact pas-id-b2e27c08fcc9673527090e1f399b59e4f876ed37 [DEBUG 00:00:52] eds_contact: reading: active cache pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:52] eds_contact: reading: in loaded cache [DEBUG 00:00:52] eds_contact: reading: in cache, available [DEBUG 00:00:52] eds_contact: reading: continue after contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:52] eds_contact: reading: read pas-id-b2e27c08fcc9673527090e1f399b59e4f876ed37: <<okay>> [DEBUG 00:00:52] eds_contact: requested 7, retrieved 10 from DB in 1 queries, misses 0/7 (0%), stalls 1 [DEBUG 00:00:52] eds_contact: ReadItemAsKey aID=(pas-id-b2e27c08fcc9673527090e1f399b59e4f876ed37,) res=0 [DEBUG 00:00:52] eds_contact: reading: getting contact pas-id-c9f94aa15be0ffe38240ca0edec043a9d2b40a02 [DEBUG 00:00:52] eds_contact: reading: active cache pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:52] eds_contact: reading: in loaded cache [DEBUG 00:00:52] eds_contact: reading: in cache, available [DEBUG 00:00:52] eds_contact: reading: continue after contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:52] eds_contact: reading: read pas-id-c9f94aa15be0ffe38240ca0edec043a9d2b40a02: <<okay>> [DEBUG 00:00:52] eds_contact: requested 8, retrieved 10 from DB in 1 queries, misses 0/8 (0%), stalls 1 [DEBUG 00:00:52] eds_contact: ReadItemAsKey aID=(pas-id-c9f94aa15be0ffe38240ca0edec043a9d2b40a02,) res=0 [DEBUG 00:00:52] eds_contact: reading: getting contact pas-id-e4da37f9a350fd6706d646445701381984dd6c7e [DEBUG 00:00:52] eds_contact: reading: active cache pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:52] eds_contact: reading: in loaded cache [DEBUG 00:00:52] eds_contact: reading: in cache, available [DEBUG 00:00:52] eds_contact: reading: continue after contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:52] eds_contact: reading: read pas-id-e4da37f9a350fd6706d646445701381984dd6c7e: <<okay>> [DEBUG 00:00:52] eds_contact: requested 9, retrieved 10 from DB in 1 queries, misses 0/9 (0%), stalls 1 [DEBUG 00:00:52] eds_contact: ReadItemAsKey aID=(pas-id-e4da37f9a350fd6706d646445701381984dd6c7e,) res=0 [DEBUG 00:00:52] eds_contact: reading: getting contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:52] eds_contact: reading: active cache pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206-pas-id-fbb979968dab877362e487166956e68299961db2 (10) [DEBUG 00:00:52] eds_contact: reading: in loaded cache [DEBUG 00:00:52] eds_contact: reading: in cache, available [DEBUG 00:00:52] eds_contact: reading: continue after contact pas-id-fbb979968dab877362e487166956e68299961db2 [DEBUG 00:00:52] eds_contact: reading: read pas-id-fbb979968dab877362e487166956e68299961db2: <<okay>> [DEBUG 00:00:52] eds_contact: requested 10, retrieved 10 from DB in 1 queries, misses 0/10 (0%), stalls 1 [DEBUG 00:00:52] eds_contact: ReadItemAsKey aID=(pas-id-fbb979968dab877362e487166956e68299961db2,) res=0 [DEBUG 00:00:52] eds_contact: StartDataWrite [DEBUG 00:00:52] eds_contact: total number of items received 0 [INFO 00:00:52] eds_contact: sent 10/10 [INFO 00:00:56] eds_contact: started [DEBUG 00:00:56] eds_contact: total number of items received 0 [DEBUG 00:00:57] eds_contact: EndDataWrite COMMIT '1' res=0 [DEBUG 00:00:57] eds_contact: DeleteContext [INFO 00:00:57] eds_contact: normal sync done successfully [DEBUG 00:00:57] closing session [DEBUG 00:00:57] session closed [DEBUG 00:00:57] SuspendFlags: deactivating fds 38->37 [DEBUG 00:00:57] SuspendFlags: close m_receiverFD 37 [DEBUG 00:00:57] SuspendFlags: close m_senderFD 38 [DEBUG 00:00:57] SuspendFlags: done with deactivation [DEBUG 00:00:57] Module_DeleteContext eds_contact [INFO 00:00:57] sync report: [INFO 00:00:57] +---------------|-----------------------|-----------------------|-CON-+ [INFO 00:00:57] | | LOCAL | REMOTE | FLI | [INFO 00:00:57] | Source | NEW | MOD | DEL | ERR | NEW | MOD | DEL | ERR | CTS | [INFO 00:00:57] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:00:57] | eds_contact | 0 | 0 | 0 | 0 | 10 | 0 | 0 | 0 | 0 | [INFO 00:00:57] | two-way, 2 KB sent by client, 0 KB received | [INFO 00:00:57] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:00:57] | start Fri Jan 5 19:00:47 2018, duration 0:25min | [INFO 00:00:57] | synchronization completed successfully | [INFO 00:00:57] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:00:57] ----------|--------CLIENT---------|--------SERVER---------| [INFO 00:00:57] | NEW | MOD | DEL | NEW | MOD | DEL | [INFO 00:00:57] ----------|-----------------------------------------------| [INFO 00:00:57] Expected | 0 | 0 | 0 | 10 | 0 | 0 | [INFO 00:00:57] Expected sync mode: two-way [INFO 00:00:57] Expected cycles: 1 [INFO 00:00:57] [DEBUG 00:00:57] ClientTest.cpp:8283: starting CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:00:57] ClientTest.cpp:8283: ending CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:00:57] ClientTest.cpp:8284: starting CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:00:57] ClientTest.cpp:8284: ending CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:00:57] Checking sync source eds_contact... [DEBUG 00:00:57] ClientTest.cpp:8293: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:00:57] ClientTest.cpp:8293: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:00:57] ClientTest.cpp:8305: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:00:57] ClientTest.cpp:8305: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:00:57] ClientTest.cpp:8308: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:00:57] ClientTest.cpp:8308: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:00:57] ClientTest.cpp:8319: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:00:57] ClientTest.cpp:8319: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:00:57] ClientTest.cpp:8322: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:00:57] ClientTest.cpp:8322: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:00:57] ClientTest.cpp:8328: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(clientAdded),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8328: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(clientAdded),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8334: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8334: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8340: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(clientDeleted),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8340: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(clientDeleted),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8347: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8347: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8353: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8353: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8359: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(serverDeleted),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] ClientTest.cpp:8359: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(serverDeleted),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:00:57] Done with checking sync report. [DEBUG 00:00:57] ClientTest.cpp:6460: ending res = client.doSync(sourceArray, logname, options) [DEBUG 00:00:57] ClientTest.cpp:6465: starting postSync(res, logname) [DEBUG 00:00:57] ClientTest.cpp:6465: ending postSync(res, logname) [DEBUG 00:00:57] ClientTest.cpp:4630: ending doSync(logPrefix, options) [DEBUG 00:00:57] ClientTest.cpp:4638: starting refreshClient() [DEBUG 00:00:57] ClientTest.cpp:3160: starting doSync(logPrefix, options) [DEBUG 00:00:57] 3. starting Client_Sync_eds_contact_testManyDeletes.refresh.client.A with sync mode refresh-from-remote [DEBUG 00:00:57] ClientTest.cpp:6460: starting res = client.doSync(sourceArray, logname, options) [DEBUG 00:00:57] log path -> /data/runtests/work/testing-amd64/home/edsdav/cache/syncevolution, No such file or directory [DEBUG 00:00:57] log path -> Client_Sync_eds_contact_testManyDeletes.refresh.client.A, No such file or directory [DEBUG 00:00:57] log path -> Client_Sync_eds_contact_testManyDeletes.refresh.client.A, No such file or directory [DEBUG 00:00:57] checking log dir Client_Sync_eds_contact_testManyDeletes.refresh.client.A [DEBUG 00:00:57] logfile: Client_Sync_eds_contact_testManyDeletes.refresh.client.A/syncevolution-log.html [DEVELOPER 00:00:59] SyncML server account: user01 [DEVELOPER 00:00:59] client: SyncEvolution 1.5.3 for workstation [DEVELOPER 00:00:59] device ID: client-edsdav_1 [DEVELOPER 00:00:59] [DEVELOPER 00:00:59] [INFO 00:00:59] addressbook: inactive [INFO 00:00:59] calendar: inactive [INFO 00:00:59] calendar+todo: inactive [INFO 00:00:59] eas_contact: inactive [INFO 00:00:59] eas_event: inactive [INFO 00:00:59] eas_memo: inactive [INFO 00:00:59] eas_task: inactive [INFO 00:00:59] eds_event: inactive [INFO 00:00:59] eds_memo: inactive [INFO 00:00:59] eds_task: inactive [INFO 00:00:59] file_calendar+todo: inactive [INFO 00:00:59] file_contact: inactive [INFO 00:00:59] file_event: inactive [INFO 00:00:59] file_task: inactive [INFO 00:00:59] kde_contact: inactive [INFO 00:00:59] kde_event: inactive [INFO 00:00:59] kde_memo: inactive [INFO 00:00:59] kde_task: inactive [INFO 00:00:59] memo: inactive [INFO 00:00:59] todo: inactive [DEBUG 00:00:59] checking password property 'password' in config 'edsdav_1@client-test-edsdav-1' with user identity 'user01' [DEBUG 00:00:59] loading password from keyring with key user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:00:59] not using KWallet [DEBUG 00:00:59] sync password for edsdav_1@client-test-edsdav-1: loaded password from GNOME keyring using user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:00:59] checking password property 'databasePassword' in datastore 'eds_contact' of config 'edsdav_1@client-test-edsdav-1' with user identity '' [DEBUG 00:00:59] sync is starting, catch signals [DEBUG 00:00:59] SuspendFlags: (re)activating, currently inactive [DEBUG 00:00:59] SuspendFlags: activating signal handler(s) with fds 38->37 [DEBUG 00:00:59] SuspendFlags: catch signal 15 [DEBUG 00:00:59] ready to sync [DEBUG 00:01:00] CreateContext SyncEvolution//eds_contact => 0 [DEBUG 00:01:00] Module_Version = 01090100 [DEBUG 00:01:00] Module_Capabilities: [DEBUG 00:01:00] PLATFORM:Linux [DEBUG 00:01:00] DLL:true [DEBUG 00:01:00] MINVERSION:V1.0.6.0 [DEBUG 00:01:00] MANUFACTURER:SyncEvolution [DEBUG 00:01:00] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:01:00] plugin_datastore_str:no [DEBUG 00:01:00] plugin_datastore_key:yes [DEBUG 00:01:00] ITEM_AS_KEY:yes [DEBUG 00:01:00] plugin_datablob:no [DEBUG 00:01:00] eds_contact: Module_PluginParams [DEBUG 00:01:00] eds_contact: Engine=01090100 [DEBUG 00:01:00] eds_contact: [DEBUG 00:01:00] Module_Capabilities: [DEBUG 00:01:00] PLATFORM:Linux [DEBUG 00:01:00] DLL:true [DEBUG 00:01:00] MINVERSION:V1.0.6.0 [DEBUG 00:01:00] MANUFACTURER:SyncEvolution [DEBUG 00:01:00] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:01:00] plugin_datastore_str:no [DEBUG 00:01:00] plugin_datastore_key:yes [DEBUG 00:01:00] ITEM_AS_KEY:yes [DEBUG 00:01:00] plugin_datablob:no [DEBUG 00:01:00] copying syncURL, username, password to Synthesis engine [DEBUG 00:01:00] using plain username/password for user01 [DEBUG 00:01:00] eds_contact: total number of items received 0 [INFO 00:01:16] eds_contact: starting first time sync from server (peer is server) [DEBUG 00:01:16] reading: set read-ahead based on sync mode refresh-from-remote [DEBUG 00:01:16] eds_contact: reading: set order 'none', 0 luids [DEBUG 00:01:16] eds_contact: 'eds_contact' dev='anydevice' usr='singleuser' err=0 [DEBUG 00:01:16] eds_contact: FilterSupport staticfilter: [DEBUG 00:01:16] eds_contact: dynamicfilter: [DEBUG 00:01:16] eds_contact: invisiblefilter: [DEBUG 00:01:16] eds_contact: ContextSupport ReadNextItem:allfields [DEBUG 00:01:16] eds_contact: [DEBUG 00:01:16] eds_contact: slow sync or testing, do full item scan to detect changes [DEBUG 00:01:16] eds_contact: StartDataRead last='' resume='' res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206,(null)) res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-1724c66f21a14ffa33dab6aad01d623bcf38cf3f,(null)) res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-2224ebc390e29d2c58dc0f55307e908cfb695af6,(null)) res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-445ae45f630bcda9b6717a961a48f665c5a174a6,(null)) res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-77131a5a1bc2321ef59cac200c3376f2f7e39376,(null)) res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-ac218fa54de3f7bad05a25c8a054755e81c95714,(null)) res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-b2e27c08fcc9673527090e1f399b59e4f876ed37,(null)) res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-c9f94aa15be0ffe38240ca0edec043a9d2b40a02,(null)) res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-e4da37f9a350fd6706d646445701381984dd6c7e,(null)) res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-fbb979968dab877362e487166956e68299961db2,(null)) res=0 [DEBUG 00:01:16] eds_contact: ReadNextItemAsKey aStatus=0 aID=((null),(null)) res=0 [DEBUG 00:01:16] eds_contact: EndDataRead res=0 [DEBUG 00:01:16] eds_contact: StartDataWrite [DEBUG 00:01:16] eds_contact: DeleteSyncSet not implemented [DEBUG 00:01:16] eds_contact: reading: getting contact pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206 [INFO 00:01:16] eds_contact: deleting "002- Doe" [DEBUG 00:01:16] eds_contact: DeleteItem aID=(pas-id-071e6341aeb8046f1b16a757ab1d72ef714eb206,) res=0 [DEBUG 00:01:16] eds_contact: reading: getting contact pas-id-1724c66f21a14ffa33dab6aad01d623bcf38cf3f [INFO 00:01:16] eds_contact: deleting "008- Doe" [DEBUG 00:01:16] eds_contact: DeleteItem aID=(pas-id-1724c66f21a14ffa33dab6aad01d623bcf38cf3f,) res=0 [DEBUG 00:01:16] eds_contact: reading: getting contact pas-id-2224ebc390e29d2c58dc0f55307e908cfb695af6 [INFO 00:01:16] eds_contact: deleting "007- Doe" [DEBUG 00:01:16] eds_contact: DeleteItem aID=(pas-id-2224ebc390e29d2c58dc0f55307e908cfb695af6,) res=0 [DEBUG 00:01:16] eds_contact: reading: getting contact pas-id-445ae45f630bcda9b6717a961a48f665c5a174a6 [INFO 00:01:16] eds_contact: deleting "006- Doe" [DEBUG 00:01:16] eds_contact: DeleteItem aID=(pas-id-445ae45f630bcda9b6717a961a48f665c5a174a6,) res=0 [DEBUG 00:01:16] eds_contact: reading: getting contact pas-id-77131a5a1bc2321ef59cac200c3376f2f7e39376 [INFO 00:01:16] eds_contact: deleting "004- Doe" [DEBUG 00:01:16] eds_contact: DeleteItem aID=(pas-id-77131a5a1bc2321ef59cac200c3376f2f7e39376,) res=0 [DEBUG 00:01:16] eds_contact: reading: getting contact pas-id-ac218fa54de3f7bad05a25c8a054755e81c95714 [INFO 00:01:16] eds_contact: deleting "005- Doe" [DEBUG 00:01:16] eds_contact: DeleteItem aID=(pas-id-ac218fa54de3f7bad05a25c8a054755e81c95714,) res=0 [DEBUG 00:01:16] eds_contact: reading: getting contact pas-id-b2e27c08fcc9673527090e1f399b59e4f876ed37 [INFO 00:01:16] eds_contact: deleting "009- Doe" [DEBUG 00:01:16] eds_contact: DeleteItem aID=(pas-id-b2e27c08fcc9673527090e1f399b59e4f876ed37,) res=0 [DEBUG 00:01:16] eds_contact: reading: getting contact pas-id-c9f94aa15be0ffe38240ca0edec043a9d2b40a02 [INFO 00:01:16] eds_contact: deleting "001- Doe" [DEBUG 00:01:16] eds_contact: DeleteItem aID=(pas-id-c9f94aa15be0ffe38240ca0edec043a9d2b40a02,) res=0 [DEBUG 00:01:16] eds_contact: reading: getting contact pas-id-e4da37f9a350fd6706d646445701381984dd6c7e [INFO 00:01:16] eds_contact: deleting "000- Doe" [DEBUG 00:01:16] eds_contact: DeleteItem aID=(pas-id-e4da37f9a350fd6706d646445701381984dd6c7e,) res=0 [DEBUG 00:01:16] eds_contact: reading: getting contact pas-id-fbb979968dab877362e487166956e68299961db2 [INFO 00:01:16] eds_contact: deleting "003- Doe" [DEBUG 00:01:16] eds_contact: DeleteItem aID=(pas-id-fbb979968dab877362e487166956e68299961db2,) res=0 [DEBUG 00:01:16] eds_contact: total number of items received 0 [INFO 00:01:16] eds_contact: deleting 10/10 [INFO 00:01:20] eds_contact: started [INFO 00:01:20] eds_contact: adding "009- Doe" [DEBUG 00:01:20] eds_contact: add operation #0: queueing for batched add [DEBUG 00:01:20] eds_contact: InsertItemAsKey res=1 [INFO 00:01:20] eds_contact: adding "001- Doe" [DEBUG 00:01:20] eds_contact: add operation #1: queueing for batched add [DEBUG 00:01:20] eds_contact: InsertItemAsKey res=1 [INFO 00:01:20] eds_contact: adding "006- Doe" [DEBUG 00:01:20] eds_contact: add operation #2: queueing for batched add [DEBUG 00:01:20] eds_contact: InsertItemAsKey res=1 [INFO 00:01:21] eds_contact: adding "004- Doe" [DEBUG 00:01:21] eds_contact: add operation #3: queueing for batched add [DEBUG 00:01:21] eds_contact: InsertItemAsKey res=1 [INFO 00:01:21] eds_contact: adding "002- Doe" [DEBUG 00:01:21] eds_contact: add operation #4: queueing for batched add [DEBUG 00:01:21] eds_contact: InsertItemAsKey res=1 [INFO 00:01:21] eds_contact: adding "008- Doe" [DEBUG 00:01:21] eds_contact: add operation #5: queueing for batched add [DEBUG 00:01:21] eds_contact: InsertItemAsKey res=1 [INFO 00:01:21] eds_contact: adding "007- Doe" [DEBUG 00:01:21] eds_contact: add operation #6: queueing for batched add [DEBUG 00:01:21] eds_contact: InsertItemAsKey res=1 [INFO 00:01:21] eds_contact: adding "005- Doe" [DEBUG 00:01:21] eds_contact: add operation #7: queueing for batched add [DEBUG 00:01:21] eds_contact: InsertItemAsKey res=1 [INFO 00:01:21] eds_contact: adding "000- Doe" [DEBUG 00:01:21] eds_contact: add operation #8: queueing for batched add [DEBUG 00:01:21] eds_contact: InsertItemAsKey res=1 [INFO 00:01:22] eds_contact: adding "003- Doe" [DEBUG 00:01:22] eds_contact: add operation #9: queueing for batched add [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=1 [DEBUG 00:01:22] eds_contact: batch add of 10 contacts starting [DEBUG 00:01:22] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:01:22] eds_contact: batch add of 10 contacts completed [DEBUG 00:01:22] eds_contact: add operation #0: completed: <<successfully>> [DEBUG 00:01:22] eds_contact: add operation #1: completed: <<successfully>> [DEBUG 00:01:22] eds_contact: add operation #2: completed: <<successfully>> [DEBUG 00:01:22] eds_contact: add operation #3: completed: <<successfully>> [DEBUG 00:01:22] eds_contact: add operation #4: completed: <<successfully>> [DEBUG 00:01:22] eds_contact: add operation #5: completed: <<successfully>> [DEBUG 00:01:22] eds_contact: add operation #6: completed: <<successfully>> [DEBUG 00:01:22] eds_contact: add operation #7: completed: <<successfully>> [DEBUG 00:01:22] eds_contact: add operation #8: completed: <<successfully>> [DEBUG 00:01:22] eds_contact: add operation #9: completed: <<successfully>> [DEBUG 00:01:22] eds_contact: pending operations completed [DEBUG 00:01:22] eds_contact: add operation #0: checking operation: inserted [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:22] eds_contact: add operation #1: checking operation: inserted [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:22] eds_contact: add operation #2: checking operation: inserted [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:22] eds_contact: add operation #3: checking operation: inserted [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:22] eds_contact: add operation #4: checking operation: inserted [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:22] eds_contact: add operation #5: checking operation: inserted [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:22] eds_contact: add operation #6: checking operation: inserted [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:22] eds_contact: add operation #7: checking operation: inserted [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:22] eds_contact: add operation #8: checking operation: inserted [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:22] eds_contact: add operation #9: checking operation: inserted [DEBUG 00:01:22] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:23] eds_contact: EndDataWrite COMMIT '1' res=0 [DEBUG 00:01:23] eds_contact: total number of items received 0 [INFO 00:01:23] eds_contact: received 20/10 [DEBUG 00:01:23] eds_contact: DeleteContext [INFO 00:01:23] eds_contact: first time sync done successfully [DEBUG 00:01:23] closing session [DEBUG 00:01:23] session closed [DEBUG 00:01:23] SuspendFlags: deactivating fds 38->37 [DEBUG 00:01:23] SuspendFlags: close m_receiverFD 37 [DEBUG 00:01:23] SuspendFlags: close m_senderFD 38 [DEBUG 00:01:23] SuspendFlags: done with deactivation [DEBUG 00:01:23] Module_DeleteContext eds_contact [INFO 00:01:23] sync report: [INFO 00:01:23] +---------------|-----------------------|-----------------------|-CON-+ [INFO 00:01:23] | | LOCAL | REMOTE | FLI | [INFO 00:01:23] | Source | NEW | MOD | DEL | ERR | NEW | MOD | DEL | ERR | CTS | [INFO 00:01:23] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:01:23] | eds_contact | 10 | 0 | 10 | 0 | 0 | 0 | 0 | 0 | 0 | [INFO 00:01:23] | refresh-from-remote, 0 KB sent by client, 2 KB received | [INFO 00:01:23] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:01:23] | start Fri Jan 5 19:01:12 2018, duration 0:26min | [INFO 00:01:23] | synchronization completed successfully | [INFO 00:01:23] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:01:23] ----------|--------CLIENT---------|--------SERVER---------| [INFO 00:01:23] | NEW | MOD | DEL | NEW | MOD | DEL | [INFO 00:01:23] ----------|-----------------------------------------------| [INFO 00:01:23] Expected | -1 | 0 | -1 | 0 | 0 | 0 | [INFO 00:01:23] Expected sync mode: refresh-from-remote [INFO 00:01:23] Expected cycles: 1 [INFO 00:01:23] [DEBUG 00:01:23] ClientTest.cpp:8283: starting CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:01:23] ClientTest.cpp:8283: ending CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:01:23] ClientTest.cpp:8284: starting CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:01:23] ClientTest.cpp:8284: ending CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:01:23] Checking sync source eds_contact... [DEBUG 00:01:23] ClientTest.cpp:8293: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:01:23] ClientTest.cpp:8293: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:01:23] ClientTest.cpp:8305: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:01:23] ClientTest.cpp:8305: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:01:23] ClientTest.cpp:8308: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:01:23] ClientTest.cpp:8308: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:01:23] ClientTest.cpp:8319: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:01:23] ClientTest.cpp:8319: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:01:23] ClientTest.cpp:8322: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:01:23] ClientTest.cpp:8322: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:01:23] ClientTest.cpp:8334: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:23] ClientTest.cpp:8334: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:23] ClientTest.cpp:8347: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:23] ClientTest.cpp:8347: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:23] ClientTest.cpp:8353: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:23] ClientTest.cpp:8353: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:23] ClientTest.cpp:8359: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(serverDeleted),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:23] ClientTest.cpp:8359: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(serverDeleted),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:23] Done with checking sync report. [DEBUG 00:01:23] ClientTest.cpp:6460: ending res = client.doSync(sourceArray, logname, options) [DEBUG 00:01:23] ClientTest.cpp:6465: starting postSync(res, logname) [DEBUG 00:01:23] ClientTest.cpp:6465: ending postSync(res, logname) [DEBUG 00:01:23] ClientTest.cpp:3160: ending doSync(logPrefix, options) [DEBUG 00:01:23] ClientTest.cpp:4638: ending refreshClient() [DEBUG 00:01:23] ClientTest.cpp:3160: starting doSync(logPrefix, options) [DEBUG 00:01:23] 4. starting Client_Sync_eds_contact_testManyDeletes.refresh.client.B with sync mode refresh-from-remote [DEBUG 00:01:23] ClientTest.cpp:6460: starting res = client.doSync(sourceArray, logname, options) [DEBUG 00:01:23] log path -> /data/runtests/work/testing-amd64/home/edsdav/cache/syncevolution, No such file or directory [DEBUG 00:01:23] log path -> Client_Sync_eds_contact_testManyDeletes.refresh.client.B, No such file or directory [DEBUG 00:01:23] log path -> Client_Sync_eds_contact_testManyDeletes.refresh.client.B, No such file or directory [DEBUG 00:01:23] checking log dir Client_Sync_eds_contact_testManyDeletes.refresh.client.B [DEBUG 00:01:23] logfile: Client_Sync_eds_contact_testManyDeletes.refresh.client.B/syncevolution-log.html [DEVELOPER 00:01:25] SyncML server account: user01 [DEVELOPER 00:01:25] client: SyncEvolution 1.5.3 for workstation [DEVELOPER 00:01:25] device ID: client-edsdav_2 [DEVELOPER 00:01:25] [DEVELOPER 00:01:25] [INFO 00:01:25] addressbook: inactive [INFO 00:01:25] calendar: inactive [INFO 00:01:25] calendar+todo: inactive [INFO 00:01:25] eas_contact: inactive [INFO 00:01:25] eas_event: inactive [INFO 00:01:25] eas_memo: inactive [INFO 00:01:25] eas_task: inactive [INFO 00:01:26] eds_event: inactive [INFO 00:01:26] eds_memo: inactive [INFO 00:01:26] eds_task: inactive [INFO 00:01:26] file_calendar+todo: inactive [INFO 00:01:26] file_contact: inactive [INFO 00:01:26] file_event: inactive [INFO 00:01:26] file_task: inactive [INFO 00:01:26] kde_contact: inactive [INFO 00:01:26] kde_event: inactive [INFO 00:01:26] kde_memo: inactive [INFO 00:01:26] kde_task: inactive [INFO 00:01:26] memo: inactive [INFO 00:01:26] todo: inactive [DEBUG 00:01:26] checking password property 'password' in config 'edsdav_2@client-test-edsdav-2' with user identity 'user01' [DEBUG 00:01:26] loading password from keyring with key user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:01:26] not using KWallet [DEBUG 00:01:26] sync password for edsdav_2@client-test-edsdav-2: loaded password from GNOME keyring using user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:01:26] checking password property 'databasePassword' in datastore 'eds_contact' of config 'edsdav_2@client-test-edsdav-2' with user identity '' [DEBUG 00:01:26] sync is starting, catch signals [DEBUG 00:01:26] SuspendFlags: (re)activating, currently inactive [DEBUG 00:01:26] SuspendFlags: activating signal handler(s) with fds 38->37 [DEBUG 00:01:26] SuspendFlags: catch signal 15 [DEBUG 00:01:26] ready to sync [DEBUG 00:01:26] CreateContext SyncEvolution//eds_contact => 0 [DEBUG 00:01:26] Module_Version = 01090100 [DEBUG 00:01:26] Module_Capabilities: [DEBUG 00:01:26] PLATFORM:Linux [DEBUG 00:01:26] DLL:true [DEBUG 00:01:26] MINVERSION:V1.0.6.0 [DEBUG 00:01:26] MANUFACTURER:SyncEvolution [DEBUG 00:01:26] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:01:26] plugin_datastore_str:no [DEBUG 00:01:26] plugin_datastore_key:yes [DEBUG 00:01:26] ITEM_AS_KEY:yes [DEBUG 00:01:26] plugin_datablob:no [DEBUG 00:01:26] eds_contact: Module_PluginParams [DEBUG 00:01:26] eds_contact: Engine=01090100 [DEBUG 00:01:26] eds_contact: [DEBUG 00:01:26] Module_Capabilities: [DEBUG 00:01:26] PLATFORM:Linux [DEBUG 00:01:26] DLL:true [DEBUG 00:01:26] MINVERSION:V1.0.6.0 [DEBUG 00:01:26] MANUFACTURER:SyncEvolution [DEBUG 00:01:26] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:01:26] plugin_datastore_str:no [DEBUG 00:01:26] plugin_datastore_key:yes [DEBUG 00:01:26] ITEM_AS_KEY:yes [DEBUG 00:01:26] plugin_datablob:no [DEBUG 00:01:26] copying syncURL, username, password to Synthesis engine [DEBUG 00:01:26] using plain username/password for user01 [DEBUG 00:01:26] eds_contact: total number of items received 0 [INFO 00:01:43] eds_contact: starting first time sync from server (peer is server) [DEBUG 00:01:43] reading: set read-ahead based on sync mode refresh-from-remote [DEBUG 00:01:43] eds_contact: reading: set order 'none', 0 luids [DEBUG 00:01:43] eds_contact: 'eds_contact' dev='anydevice' usr='singleuser' err=0 [DEBUG 00:01:43] eds_contact: FilterSupport staticfilter: [DEBUG 00:01:43] eds_contact: dynamicfilter: [DEBUG 00:01:43] eds_contact: invisiblefilter: [DEBUG 00:01:43] eds_contact: ContextSupport ReadNextItem:allfields [DEBUG 00:01:43] eds_contact: [DEBUG 00:01:43] eds_contact: slow sync or testing, do full item scan to detect changes [DEBUG 00:01:43] eds_contact: StartDataRead last='' resume='' res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-0ec90277431a41eba08a604024260f1d2af3483c,(null)) res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-31207ecbe010f975fea22c41159a5a95debe743a,(null)) res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-3331f90a1f77a23b8f7246ae20bfc4023ac1940d,(null)) res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-4dd8f452f4ed719608eef9af01e8360d714b4d40,(null)) res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-7ffeeba04932f8ba1cf5c10cd8b948ea5de5980a,(null)) res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-8354be515cde9dfbdefc8be849021b2aa4a96247,(null)) res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-8cc201a135f012930615ec06ed116b2ccc45bb6b,(null)) res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-93c9c0434e0a4d650cf4e739c73dd37e06ba6cca,(null)) res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-a2643f2d6f392cda5fc857e436bcb5826106a2eb,(null)) res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-ab6515064e8698b255f941ddbc7bf572441ed075,(null)) res=0 [DEBUG 00:01:43] eds_contact: ReadNextItemAsKey aStatus=0 aID=((null),(null)) res=0 [DEBUG 00:01:43] eds_contact: EndDataRead res=0 [DEBUG 00:01:43] eds_contact: StartDataWrite [DEBUG 00:01:43] eds_contact: DeleteSyncSet not implemented [DEBUG 00:01:43] eds_contact: reading: getting contact pas-id-0ec90277431a41eba08a604024260f1d2af3483c [INFO 00:01:43] eds_contact: deleting "002- Doe" [DEBUG 00:01:43] eds_contact: DeleteItem aID=(pas-id-0ec90277431a41eba08a604024260f1d2af3483c,) res=0 [DEBUG 00:01:43] eds_contact: reading: getting contact pas-id-31207ecbe010f975fea22c41159a5a95debe743a [INFO 00:01:43] eds_contact: deleting "000- Doe" [DEBUG 00:01:43] eds_contact: DeleteItem aID=(pas-id-31207ecbe010f975fea22c41159a5a95debe743a,) res=0 [DEBUG 00:01:43] eds_contact: reading: getting contact pas-id-3331f90a1f77a23b8f7246ae20bfc4023ac1940d [INFO 00:01:43] eds_contact: deleting "007- Doe" [DEBUG 00:01:43] eds_contact: DeleteItem aID=(pas-id-3331f90a1f77a23b8f7246ae20bfc4023ac1940d,) res=0 [DEBUG 00:01:43] eds_contact: reading: getting contact pas-id-4dd8f452f4ed719608eef9af01e8360d714b4d40 [INFO 00:01:43] eds_contact: deleting "008- Doe" [DEBUG 00:01:43] eds_contact: DeleteItem aID=(pas-id-4dd8f452f4ed719608eef9af01e8360d714b4d40,) res=0 [DEBUG 00:01:43] eds_contact: reading: getting contact pas-id-7ffeeba04932f8ba1cf5c10cd8b948ea5de5980a [INFO 00:01:43] eds_contact: deleting "005- Doe" [DEBUG 00:01:43] eds_contact: DeleteItem aID=(pas-id-7ffeeba04932f8ba1cf5c10cd8b948ea5de5980a,) res=0 [DEBUG 00:01:43] eds_contact: reading: getting contact pas-id-8354be515cde9dfbdefc8be849021b2aa4a96247 [INFO 00:01:43] eds_contact: deleting "004- Doe" [DEBUG 00:01:43] eds_contact: DeleteItem aID=(pas-id-8354be515cde9dfbdefc8be849021b2aa4a96247,) res=0 [DEBUG 00:01:43] eds_contact: reading: getting contact pas-id-8cc201a135f012930615ec06ed116b2ccc45bb6b [INFO 00:01:43] eds_contact: deleting "001- Doe" [DEBUG 00:01:43] eds_contact: DeleteItem aID=(pas-id-8cc201a135f012930615ec06ed116b2ccc45bb6b,) res=0 [DEBUG 00:01:43] eds_contact: reading: getting contact pas-id-93c9c0434e0a4d650cf4e739c73dd37e06ba6cca [INFO 00:01:43] eds_contact: deleting "009- Doe" [DEBUG 00:01:43] eds_contact: DeleteItem aID=(pas-id-93c9c0434e0a4d650cf4e739c73dd37e06ba6cca,) res=0 [DEBUG 00:01:43] eds_contact: reading: getting contact pas-id-a2643f2d6f392cda5fc857e436bcb5826106a2eb [INFO 00:01:43] eds_contact: deleting "006- Doe" [DEBUG 00:01:43] eds_contact: DeleteItem aID=(pas-id-a2643f2d6f392cda5fc857e436bcb5826106a2eb,) res=0 [DEBUG 00:01:43] eds_contact: reading: getting contact pas-id-ab6515064e8698b255f941ddbc7bf572441ed075 [INFO 00:01:43] eds_contact: deleting "003- Doe" [DEBUG 00:01:43] eds_contact: DeleteItem aID=(pas-id-ab6515064e8698b255f941ddbc7bf572441ed075,) res=0 [DEBUG 00:01:43] eds_contact: total number of items received 0 [INFO 00:01:43] eds_contact: deleting 10/10 [INFO 00:01:46] eds_contact: started [INFO 00:01:46] eds_contact: adding "009- Doe" [DEBUG 00:01:46] eds_contact: add operation #0: queueing for batched add [DEBUG 00:01:46] eds_contact: InsertItemAsKey res=1 [INFO 00:01:46] eds_contact: adding "001- Doe" [DEBUG 00:01:46] eds_contact: add operation #1: queueing for batched add [DEBUG 00:01:46] eds_contact: InsertItemAsKey res=1 [INFO 00:01:46] eds_contact: adding "006- Doe" [DEBUG 00:01:46] eds_contact: add operation #2: queueing for batched add [DEBUG 00:01:46] eds_contact: InsertItemAsKey res=1 [INFO 00:01:46] eds_contact: adding "004- Doe" [DEBUG 00:01:46] eds_contact: add operation #3: queueing for batched add [DEBUG 00:01:46] eds_contact: InsertItemAsKey res=1 [INFO 00:01:47] eds_contact: adding "002- Doe" [DEBUG 00:01:47] eds_contact: add operation #4: queueing for batched add [DEBUG 00:01:47] eds_contact: InsertItemAsKey res=1 [INFO 00:01:47] eds_contact: adding "008- Doe" [DEBUG 00:01:47] eds_contact: add operation #5: queueing for batched add [DEBUG 00:01:47] eds_contact: InsertItemAsKey res=1 [INFO 00:01:47] eds_contact: adding "007- Doe" [DEBUG 00:01:47] eds_contact: add operation #6: queueing for batched add [DEBUG 00:01:47] eds_contact: InsertItemAsKey res=1 [INFO 00:01:47] eds_contact: adding "005- Doe" [DEBUG 00:01:47] eds_contact: add operation #7: queueing for batched add [DEBUG 00:01:47] eds_contact: InsertItemAsKey res=1 [INFO 00:01:47] eds_contact: adding "000- Doe" [DEBUG 00:01:47] eds_contact: add operation #8: queueing for batched add [DEBUG 00:01:47] eds_contact: InsertItemAsKey res=1 [INFO 00:01:48] eds_contact: adding "003- Doe" [DEBUG 00:01:48] eds_contact: add operation #9: queueing for batched add [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=1 [DEBUG 00:01:48] eds_contact: batch add of 10 contacts starting [DEBUG 00:01:48] eds_contact: waiting for 1 pending operations to complete [DEBUG 00:01:48] eds_contact: batch add of 10 contacts completed [DEBUG 00:01:48] eds_contact: add operation #0: completed: <<successfully>> [DEBUG 00:01:48] eds_contact: add operation #1: completed: <<successfully>> [DEBUG 00:01:48] eds_contact: add operation #2: completed: <<successfully>> [DEBUG 00:01:48] eds_contact: add operation #3: completed: <<successfully>> [DEBUG 00:01:48] eds_contact: add operation #4: completed: <<successfully>> [DEBUG 00:01:48] eds_contact: add operation #5: completed: <<successfully>> [DEBUG 00:01:48] eds_contact: add operation #6: completed: <<successfully>> [DEBUG 00:01:48] eds_contact: add operation #7: completed: <<successfully>> [DEBUG 00:01:48] eds_contact: add operation #8: completed: <<successfully>> [DEBUG 00:01:48] eds_contact: add operation #9: completed: <<successfully>> [DEBUG 00:01:48] eds_contact: pending operations completed [DEBUG 00:01:48] eds_contact: add operation #0: checking operation: inserted [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:48] eds_contact: add operation #1: checking operation: inserted [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:48] eds_contact: add operation #2: checking operation: inserted [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:48] eds_contact: add operation #3: checking operation: inserted [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:48] eds_contact: add operation #4: checking operation: inserted [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:48] eds_contact: add operation #5: checking operation: inserted [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:48] eds_contact: add operation #6: checking operation: inserted [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:48] eds_contact: add operation #7: checking operation: inserted [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:48] eds_contact: add operation #8: checking operation: inserted [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:48] eds_contact: add operation #9: checking operation: inserted [DEBUG 00:01:48] eds_contact: InsertItemAsKey res=0 [DEBUG 00:01:49] eds_contact: EndDataWrite COMMIT '1' res=0 [DEBUG 00:01:49] eds_contact: total number of items received 0 [INFO 00:01:49] eds_contact: received 20/10 [DEBUG 00:01:49] eds_contact: DeleteContext [INFO 00:01:49] eds_contact: first time sync done successfully [DEBUG 00:01:49] closing session [DEBUG 00:01:49] session closed [DEBUG 00:01:49] SuspendFlags: deactivating fds 38->37 [DEBUG 00:01:49] SuspendFlags: close m_receiverFD 37 [DEBUG 00:01:49] SuspendFlags: close m_senderFD 38 [DEBUG 00:01:49] SuspendFlags: done with deactivation [DEBUG 00:01:49] Module_DeleteContext eds_contact [INFO 00:01:49] sync report: [INFO 00:01:49] +---------------|-----------------------|-----------------------|-CON-+ [INFO 00:01:49] | | LOCAL | REMOTE | FLI | [INFO 00:01:49] | Source | NEW | MOD | DEL | ERR | NEW | MOD | DEL | ERR | CTS | [INFO 00:01:49] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:01:49] | eds_contact | 10 | 0 | 10 | 0 | 0 | 0 | 0 | 0 | 0 | [INFO 00:01:49] | refresh-from-remote, 0 KB sent by client, 2 KB received | [INFO 00:01:49] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:01:49] | start Fri Jan 5 19:01:38 2018, duration 0:26min | [INFO 00:01:49] | synchronization completed successfully | [INFO 00:01:49] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:01:49] ----------|--------CLIENT---------|--------SERVER---------| [INFO 00:01:49] | NEW | MOD | DEL | NEW | MOD | DEL | [INFO 00:01:49] ----------|-----------------------------------------------| [INFO 00:01:49] Expected | -1 | 0 | -1 | 0 | 0 | 0 | [INFO 00:01:49] Expected sync mode: refresh-from-remote [INFO 00:01:49] Expected cycles: 1 [INFO 00:01:49] [DEBUG 00:01:49] ClientTest.cpp:8283: starting CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:01:49] ClientTest.cpp:8283: ending CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:01:49] ClientTest.cpp:8284: starting CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:01:49] ClientTest.cpp:8284: ending CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:01:49] Checking sync source eds_contact... [DEBUG 00:01:49] ClientTest.cpp:8293: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:01:49] ClientTest.cpp:8293: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:01:49] ClientTest.cpp:8305: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:01:49] ClientTest.cpp:8305: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:01:49] ClientTest.cpp:8308: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:01:49] ClientTest.cpp:8308: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:01:49] ClientTest.cpp:8319: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:01:49] ClientTest.cpp:8319: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:01:49] ClientTest.cpp:8322: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:01:49] ClientTest.cpp:8322: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:01:49] ClientTest.cpp:8334: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:49] ClientTest.cpp:8334: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:49] ClientTest.cpp:8347: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:49] ClientTest.cpp:8347: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:49] ClientTest.cpp:8353: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:49] ClientTest.cpp:8353: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:49] ClientTest.cpp:8359: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(serverDeleted),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:49] ClientTest.cpp:8359: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(serverDeleted),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:01:49] Done with checking sync report. [DEBUG 00:01:49] ClientTest.cpp:6460: ending res = client.doSync(sourceArray, logname, options) [DEBUG 00:01:49] ClientTest.cpp:6465: starting postSync(res, logname) [DEBUG 00:01:49] ClientTest.cpp:6465: ending postSync(res, logname) [DEBUG 00:01:49] ClientTest.cpp:3160: ending doSync(logPrefix, options) [DEBUG 00:01:49] ClientTest.cpp:4644: starting doSync(logPrefix, options) [DEBUG 00:01:49] 5. starting Client_Sync_eds_contact_testManyDeletes.twinning.client.A with sync mode slow [DEBUG 00:01:49] ClientTest.cpp:6460: starting res = client.doSync(sourceArray, logname, options) [DEBUG 00:01:49] log path -> /data/runtests/work/testing-amd64/home/edsdav/cache/syncevolution, No such file or directory [DEBUG 00:01:49] log path -> Client_Sync_eds_contact_testManyDeletes.twinning.client.A, No such file or directory [DEBUG 00:01:49] log path -> Client_Sync_eds_contact_testManyDeletes.twinning.client.A, No such file or directory [DEBUG 00:01:49] checking log dir Client_Sync_eds_contact_testManyDeletes.twinning.client.A [DEBUG 00:01:49] logfile: Client_Sync_eds_contact_testManyDeletes.twinning.client.A/syncevolution-log.html [DEVELOPER 00:01:51] SyncML server account: user01 [DEVELOPER 00:01:51] client: SyncEvolution 1.5.3 for workstation [DEVELOPER 00:01:51] device ID: client-edsdav_1 [DEVELOPER 00:01:51] [DEVELOPER 00:01:51] [INFO 00:01:51] addressbook: inactive [INFO 00:01:51] calendar: inactive [INFO 00:01:51] calendar+todo: inactive [INFO 00:01:51] eas_contact: inactive [INFO 00:01:51] eas_event: inactive [INFO 00:01:51] eas_memo: inactive [INFO 00:01:51] eas_task: inactive [INFO 00:01:51] eds_event: inactive [INFO 00:01:51] eds_memo: inactive [INFO 00:01:51] eds_task: inactive [INFO 00:01:51] file_calendar+todo: inactive [INFO 00:01:51] file_contact: inactive [INFO 00:01:51] file_event: inactive [INFO 00:01:51] file_task: inactive [INFO 00:01:51] kde_contact: inactive [INFO 00:01:51] kde_event: inactive [INFO 00:01:51] kde_memo: inactive [INFO 00:01:51] kde_task: inactive [INFO 00:01:51] memo: inactive [INFO 00:01:51] todo: inactive [DEBUG 00:01:51] checking password property 'password' in config 'edsdav_1@client-test-edsdav-1' with user identity 'user01' [DEBUG 00:01:51] loading password from keyring with key user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:01:51] not using KWallet [DEBUG 00:01:51] sync password for edsdav_1@client-test-edsdav-1: loaded password from GNOME keyring using user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:01:51] checking password property 'databasePassword' in datastore 'eds_contact' of config 'edsdav_1@client-test-edsdav-1' with user identity '' [DEBUG 00:01:52] sync is starting, catch signals [DEBUG 00:01:52] SuspendFlags: (re)activating, currently inactive [DEBUG 00:01:52] SuspendFlags: activating signal handler(s) with fds 38->37 [DEBUG 00:01:52] SuspendFlags: catch signal 15 [DEBUG 00:01:52] ready to sync [DEBUG 00:01:52] CreateContext SyncEvolution//eds_contact => 0 [DEBUG 00:01:52] Module_Version = 01090100 [DEBUG 00:01:52] Module_Capabilities: [DEBUG 00:01:52] PLATFORM:Linux [DEBUG 00:01:52] DLL:true [DEBUG 00:01:52] MINVERSION:V1.0.6.0 [DEBUG 00:01:52] MANUFACTURER:SyncEvolution [DEBUG 00:01:52] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:01:52] plugin_datastore_str:no [DEBUG 00:01:52] plugin_datastore_key:yes [DEBUG 00:01:52] ITEM_AS_KEY:yes [DEBUG 00:01:52] plugin_datablob:no [DEBUG 00:01:52] eds_contact: Module_PluginParams [DEBUG 00:01:52] eds_contact: Engine=01090100 [DEBUG 00:01:52] eds_contact: [DEBUG 00:01:52] Module_Capabilities: [DEBUG 00:01:52] PLATFORM:Linux [DEBUG 00:01:52] DLL:true [DEBUG 00:01:52] MINVERSION:V1.0.6.0 [DEBUG 00:01:52] MANUFACTURER:SyncEvolution [DEBUG 00:01:52] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:01:52] plugin_datastore_str:no [DEBUG 00:01:52] plugin_datastore_key:yes [DEBUG 00:01:52] ITEM_AS_KEY:yes [DEBUG 00:01:52] plugin_datablob:no [DEBUG 00:01:52] copying syncURL, username, password to Synthesis engine [DEBUG 00:01:52] using plain username/password for user01 [DEBUG 00:01:52] eds_contact: total number of items received 0 [INFO 00:02:08] eds_contact: starting first time sync, two-way (peer is server) [DEBUG 00:02:08] reading: set read-ahead based on sync mode slow [DEBUG 00:02:08] eds_contact: reading: set order 'all', 0 luids [DEBUG 00:02:08] eds_contact: 'eds_contact' dev='anydevice' usr='singleuser' err=0 [DEBUG 00:02:08] eds_contact: FilterSupport staticfilter: [DEBUG 00:02:08] eds_contact: dynamicfilter: [DEBUG 00:02:08] eds_contact: invisiblefilter: [DEBUG 00:02:08] eds_contact: ContextSupport ReadNextItem:allfields [DEBUG 00:02:08] eds_contact: [DEBUG 00:02:08] eds_contact: slow sync or testing, do full item scan to detect changes [DEBUG 00:02:08] eds_contact: StartDataRead last='' resume='' res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30,(null)) res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-36801b6381e01cf428055b4fefca4eff0f5b7160,(null)) res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-39d3ede37c299f0e32c14dd36d13a2fc4a34007a,(null)) res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-509cf4a6fd10844c33791289bb02ab087c184827,(null)) res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-51816c498dd29769f96be978e9caf5c656f010ef,(null)) res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-936c99d779127b91193ce648d0eab611925f25ed,(null)) res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-e731831b172acdee28c04bc21f6de28935235678,(null)) res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-ee4b0345dcd8da5c3c243a84259da7b501477dd1,(null)) res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-fc1e4c9beb6ea2c066c359cf7dd241608a3ae35a,(null)) res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044,(null)) res=0 [DEBUG 00:02:08] eds_contact: ReadNextItemAsKey aStatus=0 aID=((null),(null)) res=0 [DEBUG 00:02:08] eds_contact: EndDataRead res=0 [DEBUG 00:02:08] eds_contact: reading: getting contact pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30 [DEBUG 00:02:08] eds_contact: reading: must read contact pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30 [DEBUG 00:02:08] eds_contact: reading: started contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:08] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:08] eds_contact: reading: in running cache [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) finished: <<successful>> [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-fc1e4c9beb6ea2c066c359cf7dd241608a3ae35a [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-ee4b0345dcd8da5c3c243a84259da7b501477dd1 [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-e731831b172acdee28c04bc21f6de28935235678 [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-936c99d779127b91193ce648d0eab611925f25ed [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-51816c498dd29769f96be978e9caf5c656f010ef [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-509cf4a6fd10844c33791289bb02ab087c184827 [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-39d3ede37c299f0e32c14dd36d13a2fc4a34007a [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-36801b6381e01cf428055b4fefca4eff0f5b7160 [DEBUG 00:02:08] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30 [DEBUG 00:02:08] eds_contact: reading: in cache, available [DEBUG 00:02:08] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:08] eds_contact: reading: read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30: <<okay>> [DEBUG 00:02:08] eds_contact: requested 1, retrieved 10 from DB in 1 queries, misses 0/1 (0%), stalls 1 [DEBUG 00:02:08] eds_contact: ReadItemAsKey aID=(pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30,) res=0 [DEBUG 00:02:08] eds_contact: reading: getting contact pas-id-36801b6381e01cf428055b4fefca4eff0f5b7160 [DEBUG 00:02:08] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:08] eds_contact: reading: in loaded cache [DEBUG 00:02:08] eds_contact: reading: in cache, available [DEBUG 00:02:08] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:08] eds_contact: reading: read pas-id-36801b6381e01cf428055b4fefca4eff0f5b7160: <<okay>> [DEBUG 00:02:08] eds_contact: requested 2, retrieved 10 from DB in 1 queries, misses 0/2 (0%), stalls 1 [DEBUG 00:02:08] eds_contact: ReadItemAsKey aID=(pas-id-36801b6381e01cf428055b4fefca4eff0f5b7160,) res=0 [DEBUG 00:02:09] eds_contact: reading: getting contact pas-id-39d3ede37c299f0e32c14dd36d13a2fc4a34007a [DEBUG 00:02:09] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:09] eds_contact: reading: in loaded cache [DEBUG 00:02:09] eds_contact: reading: in cache, available [DEBUG 00:02:09] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:09] eds_contact: reading: read pas-id-39d3ede37c299f0e32c14dd36d13a2fc4a34007a: <<okay>> [DEBUG 00:02:09] eds_contact: requested 3, retrieved 10 from DB in 1 queries, misses 0/3 (0%), stalls 1 [DEBUG 00:02:09] eds_contact: ReadItemAsKey aID=(pas-id-39d3ede37c299f0e32c14dd36d13a2fc4a34007a,) res=0 [DEBUG 00:02:09] eds_contact: reading: getting contact pas-id-509cf4a6fd10844c33791289bb02ab087c184827 [DEBUG 00:02:09] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:09] eds_contact: reading: in loaded cache [DEBUG 00:02:09] eds_contact: reading: in cache, available [DEBUG 00:02:09] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:09] eds_contact: reading: read pas-id-509cf4a6fd10844c33791289bb02ab087c184827: <<okay>> [DEBUG 00:02:09] eds_contact: requested 4, retrieved 10 from DB in 1 queries, misses 0/4 (0%), stalls 1 [DEBUG 00:02:09] eds_contact: ReadItemAsKey aID=(pas-id-509cf4a6fd10844c33791289bb02ab087c184827,) res=0 [DEBUG 00:02:09] eds_contact: reading: getting contact pas-id-51816c498dd29769f96be978e9caf5c656f010ef [DEBUG 00:02:09] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:09] eds_contact: reading: in loaded cache [DEBUG 00:02:09] eds_contact: reading: in cache, available [DEBUG 00:02:09] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:09] eds_contact: reading: read pas-id-51816c498dd29769f96be978e9caf5c656f010ef: <<okay>> [DEBUG 00:02:09] eds_contact: requested 5, retrieved 10 from DB in 1 queries, misses 0/5 (0%), stalls 1 [DEBUG 00:02:09] eds_contact: ReadItemAsKey aID=(pas-id-51816c498dd29769f96be978e9caf5c656f010ef,) res=0 [DEBUG 00:02:09] eds_contact: reading: getting contact pas-id-936c99d779127b91193ce648d0eab611925f25ed [DEBUG 00:02:09] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:09] eds_contact: reading: in loaded cache [DEBUG 00:02:09] eds_contact: reading: in cache, available [DEBUG 00:02:09] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:09] eds_contact: reading: read pas-id-936c99d779127b91193ce648d0eab611925f25ed: <<okay>> [DEBUG 00:02:09] eds_contact: requested 6, retrieved 10 from DB in 1 queries, misses 0/6 (0%), stalls 1 [DEBUG 00:02:09] eds_contact: ReadItemAsKey aID=(pas-id-936c99d779127b91193ce648d0eab611925f25ed,) res=0 [DEBUG 00:02:09] eds_contact: reading: getting contact pas-id-e731831b172acdee28c04bc21f6de28935235678 [DEBUG 00:02:09] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:09] eds_contact: reading: in loaded cache [DEBUG 00:02:09] eds_contact: reading: in cache, available [DEBUG 00:02:09] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:09] eds_contact: reading: read pas-id-e731831b172acdee28c04bc21f6de28935235678: <<okay>> [DEBUG 00:02:09] eds_contact: requested 7, retrieved 10 from DB in 1 queries, misses 0/7 (0%), stalls 1 [DEBUG 00:02:09] eds_contact: ReadItemAsKey aID=(pas-id-e731831b172acdee28c04bc21f6de28935235678,) res=0 [DEBUG 00:02:09] eds_contact: reading: getting contact pas-id-ee4b0345dcd8da5c3c243a84259da7b501477dd1 [DEBUG 00:02:09] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:09] eds_contact: reading: in loaded cache [DEBUG 00:02:09] eds_contact: reading: in cache, available [DEBUG 00:02:09] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:09] eds_contact: reading: read pas-id-ee4b0345dcd8da5c3c243a84259da7b501477dd1: <<okay>> [DEBUG 00:02:09] eds_contact: requested 8, retrieved 10 from DB in 1 queries, misses 0/8 (0%), stalls 1 [DEBUG 00:02:09] eds_contact: ReadItemAsKey aID=(pas-id-ee4b0345dcd8da5c3c243a84259da7b501477dd1,) res=0 [DEBUG 00:02:09] eds_contact: reading: getting contact pas-id-fc1e4c9beb6ea2c066c359cf7dd241608a3ae35a [DEBUG 00:02:09] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:09] eds_contact: reading: in loaded cache [DEBUG 00:02:09] eds_contact: reading: in cache, available [DEBUG 00:02:09] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:09] eds_contact: reading: read pas-id-fc1e4c9beb6ea2c066c359cf7dd241608a3ae35a: <<okay>> [DEBUG 00:02:09] eds_contact: requested 9, retrieved 10 from DB in 1 queries, misses 0/9 (0%), stalls 1 [DEBUG 00:02:09] eds_contact: ReadItemAsKey aID=(pas-id-fc1e4c9beb6ea2c066c359cf7dd241608a3ae35a,) res=0 [DEBUG 00:02:09] eds_contact: reading: getting contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:09] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:09] eds_contact: reading: in loaded cache [DEBUG 00:02:09] eds_contact: reading: in cache, available [DEBUG 00:02:09] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:09] eds_contact: reading: read pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044: <<okay>> [DEBUG 00:02:09] eds_contact: requested 10, retrieved 10 from DB in 1 queries, misses 0/10 (0%), stalls 1 [DEBUG 00:02:09] eds_contact: ReadItemAsKey aID=(pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044,) res=0 [DEBUG 00:02:09] eds_contact: StartDataWrite [DEBUG 00:02:09] eds_contact: total number of items received 0 [INFO 00:02:09] eds_contact: sent 10/10 [INFO 00:02:12] eds_contact: started [DEBUG 00:02:12] eds_contact: total number of items received 0 [DEBUG 00:02:12] eds_contact: EndDataWrite COMMIT '1' res=0 [DEBUG 00:02:12] eds_contact: DeleteContext [INFO 00:02:12] eds_contact: first time sync done successfully [DEBUG 00:02:12] closing session [DEBUG 00:02:12] session closed [DEBUG 00:02:12] SuspendFlags: deactivating fds 38->37 [DEBUG 00:02:12] SuspendFlags: close m_receiverFD 37 [DEBUG 00:02:12] SuspendFlags: close m_senderFD 38 [DEBUG 00:02:12] SuspendFlags: done with deactivation [DEBUG 00:02:12] Module_DeleteContext eds_contact [INFO 00:02:12] sync report: [INFO 00:02:12] +---------------|-----------------------|-----------------------|-CON-+ [INFO 00:02:12] | | LOCAL | REMOTE | FLI | [INFO 00:02:12] | Source | NEW | MOD | DEL | ERR | NEW | MOD | DEL | ERR | CTS | [INFO 00:02:12] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:02:12] | eds_contact | 0 | 0 | 0 | 0 | 10 | 0 | 0 | 0 | 0 | [INFO 00:02:12] | slow, 2 KB sent by client, 0 KB received | [INFO 00:02:12] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:02:12] | start Fri Jan 5 19:02:04 2018, duration 0:23min | [INFO 00:02:12] | synchronization completed successfully | [INFO 00:02:12] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:02:12] ----------|--------CLIENT---------|--------SERVER---------| [INFO 00:02:12] | NEW | MOD | DEL | NEW | MOD | DEL | [INFO 00:02:12] ----------|-----------------------------------------------| [INFO 00:02:12] Expected | -1 | -1 | -1 | -1 | -1 | -1 | [INFO 00:02:12] Expected sync mode: slow [INFO 00:02:12] Expected cycles: 1 [INFO 00:02:12] [DEBUG 00:02:12] ClientTest.cpp:8283: starting CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:02:12] ClientTest.cpp:8283: ending CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:02:12] ClientTest.cpp:8284: starting CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:02:12] ClientTest.cpp:8284: ending CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:02:12] Checking sync source eds_contact... [DEBUG 00:02:12] ClientTest.cpp:8293: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:02:12] ClientTest.cpp:8293: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:02:12] ClientTest.cpp:8305: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:12] ClientTest.cpp:8305: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:12] ClientTest.cpp:8308: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:12] ClientTest.cpp:8308: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:12] ClientTest.cpp:8319: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:02:12] ClientTest.cpp:8319: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:02:12] ClientTest.cpp:8322: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:02:12] ClientTest.cpp:8322: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:02:12] Done with checking sync report. [DEBUG 00:02:12] ClientTest.cpp:6460: ending res = client.doSync(sourceArray, logname, options) [DEBUG 00:02:12] ClientTest.cpp:6465: starting postSync(res, logname) [DEBUG 00:02:12] ClientTest.cpp:6465: ending postSync(res, logname) [DEBUG 00:02:12] ClientTest.cpp:4644: ending doSync(logPrefix, options) [DEBUG 00:02:12] ClientTest.cpp:4651: starting compareDatabases() [DEBUG 00:02:12] ClientTest.cpp:3065: starting CPPUNIT_ASSERT(accessClientB) [DEBUG 00:02:12] ClientTest.cpp:3065: ending CPPUNIT_ASSERT(accessClientB) [DEBUG 00:02:12] ClientTest.cpp:3070: starting copy.reset(it2->second->createSourceB()) [DEBUG 00:02:12] instantiating testing source eds_contact in config target-config@client-test-edsdav, with tracking name _2_B [DEBUG 00:02:12] overriding testing source eds_contact properties with the ones from config edsdav_2 = /data/runtests/work/testing-amd64/home/edsdav/config/syncevolution/client-test-edsdav-2/peers/edsdav_2 [DEBUG 00:02:12] sync = two-way (set) [DEBUG 00:02:12] uri = addressbook (set) [DEBUG 00:02:12] backend = Evolution Address Book (set) [DEBUG 00:02:12] syncFormat = (default) [DEBUG 00:02:12] forceSyncFormat = 0 (default) [DEBUG 00:02:12] database = Test_eds_contact_2 (set) [DEBUG 00:02:12] databaseFormat = (default) [DEBUG 00:02:12] databaseUser = (default) [DEBUG 00:02:12] databasePassword = (default) [DEBUG 00:02:12] ClientTest.cpp:424: starting CPPUNIT_ASSERT(get()) [DEBUG 00:02:12] ClientTest.cpp:424: ending CPPUNIT_ASSERT(get()) [DEBUG 00:02:12] ClientTest.cpp:425: starting CPPUNIT_ASSERT(!m_active) [DEBUG 00:02:12] ClientTest.cpp:425: ending CPPUNIT_ASSERT(!m_active) [DEBUG 00:02:12] ClientTest.cpp:431: starting get()->open() [DEBUG 00:02:12] ClientTest.cpp:431: ending get()->open() [DEBUG 00:02:12] eds_contact: slow sync or testing, do full item scan to detect changes [DEBUG 00:02:13] ClientTest.cpp:3070: ending copy.reset(it2->second->createSourceB()) [DEBUG 00:02:13] ClientTest.cpp:3070: starting CPPUNIT_ASSERT((copy.get())) [DEBUG 00:02:13] ClientTest.cpp:3070: ending CPPUNIT_ASSERT((copy.get())) [DEBUG 00:02:13] ClientTest.cpp:846: starting CPPUNIT_ASSERT(config.m_dump) [DEBUG 00:02:13] ClientTest.cpp:846: ending CPPUNIT_ASSERT(config.m_dump) [DEBUG 00:02:13] ClientTest.cpp:856: starting source.reset(createSourceA()) [DEBUG 00:02:13] instantiating testing source eds_contact in config target-config@client-test-edsdav, with tracking name _1_A [DEBUG 00:02:13] overriding testing source eds_contact properties with the ones from config edsdav_1 = /data/runtests/work/testing-amd64/home/edsdav/config/syncevolution/client-test-edsdav-1/peers/edsdav_1 [DEBUG 00:02:13] sync = two-way (set) [DEBUG 00:02:13] uri = addressbook (set) [DEBUG 00:02:13] backend = Evolution Address Book (set) [DEBUG 00:02:13] syncFormat = (default) [DEBUG 00:02:13] forceSyncFormat = 0 (default) [DEBUG 00:02:13] database = Test_eds_contact_1 (set) [DEBUG 00:02:13] databaseFormat = (default) [DEBUG 00:02:13] databaseUser = (default) [DEBUG 00:02:13] databasePassword = (default) [DEBUG 00:02:13] ClientTest.cpp:424: starting CPPUNIT_ASSERT(get()) [DEBUG 00:02:13] ClientTest.cpp:424: ending CPPUNIT_ASSERT(get()) [DEBUG 00:02:13] ClientTest.cpp:425: starting CPPUNIT_ASSERT(!m_active) [DEBUG 00:02:13] ClientTest.cpp:425: ending CPPUNIT_ASSERT(!m_active) [DEBUG 00:02:13] ClientTest.cpp:431: starting get()->open() [DEBUG 00:02:13] ClientTest.cpp:431: ending get()->open() [DEBUG 00:02:13] eds_contact: using full item scan to detect changes [DEBUG 00:02:13] ClientTest.cpp:856: ending source.reset(createSourceA()) [DEBUG 00:02:13] ClientTest.cpp:856: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:13] ClientTest.cpp:856: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:13] ClientTest.cpp:857: starting CPPUNIT_ASSERT_EQUAL((0),(config.m_dump(client, *source.get(), sourceFile))) [DEBUG 00:02:13] ClientTest.cpp:6698: starting CPPUNIT_ASSERT(source.getOperations().m_backupData) [DEBUG 00:02:13] ClientTest.cpp:6698: ending CPPUNIT_ASSERT(source.getOperations().m_backupData) [DEBUG 00:02:13] eds_contact: reading: set order 'selected', 10 luids [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30 [DEBUG 00:02:13] eds_contact: reading: must read contact pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30 [DEBUG 00:02:13] eds_contact: reading: started contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: in running cache [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) finished: <<successful>> [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-fc1e4c9beb6ea2c066c359cf7dd241608a3ae35a [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-ee4b0345dcd8da5c3c243a84259da7b501477dd1 [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-e731831b172acdee28c04bc21f6de28935235678 [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-936c99d779127b91193ce648d0eab611925f25ed [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-51816c498dd29769f96be978e9caf5c656f010ef [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-509cf4a6fd10844c33791289bb02ab087c184827 [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-39d3ede37c299f0e32c14dd36d13a2fc4a34007a [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-36801b6381e01cf428055b4fefca4eff0f5b7160 [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) got pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30 [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: read pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30: <<okay>> [DEBUG 00:02:13] eds_contact: requested 1, retrieved 10 from DB in 1 queries, misses 0/1 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-36801b6381e01cf428055b4fefca4eff0f5b7160 [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: read pas-id-36801b6381e01cf428055b4fefca4eff0f5b7160: <<okay>> [DEBUG 00:02:13] eds_contact: requested 2, retrieved 10 from DB in 1 queries, misses 0/2 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-39d3ede37c299f0e32c14dd36d13a2fc4a34007a [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: read pas-id-39d3ede37c299f0e32c14dd36d13a2fc4a34007a: <<okay>> [DEBUG 00:02:13] eds_contact: requested 3, retrieved 10 from DB in 1 queries, misses 0/3 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-509cf4a6fd10844c33791289bb02ab087c184827 [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: read pas-id-509cf4a6fd10844c33791289bb02ab087c184827: <<okay>> [DEBUG 00:02:13] eds_contact: requested 4, retrieved 10 from DB in 1 queries, misses 0/4 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-51816c498dd29769f96be978e9caf5c656f010ef [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: read pas-id-51816c498dd29769f96be978e9caf5c656f010ef: <<okay>> [DEBUG 00:02:13] eds_contact: requested 5, retrieved 10 from DB in 1 queries, misses 0/5 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-936c99d779127b91193ce648d0eab611925f25ed [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: read pas-id-936c99d779127b91193ce648d0eab611925f25ed: <<okay>> [DEBUG 00:02:13] eds_contact: requested 6, retrieved 10 from DB in 1 queries, misses 0/6 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-e731831b172acdee28c04bc21f6de28935235678 [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: read pas-id-e731831b172acdee28c04bc21f6de28935235678: <<okay>> [DEBUG 00:02:13] eds_contact: requested 7, retrieved 10 from DB in 1 queries, misses 0/7 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-ee4b0345dcd8da5c3c243a84259da7b501477dd1 [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: read pas-id-ee4b0345dcd8da5c3c243a84259da7b501477dd1: <<okay>> [DEBUG 00:02:13] eds_contact: requested 8, retrieved 10 from DB in 1 queries, misses 0/8 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-fc1e4c9beb6ea2c066c359cf7dd241608a3ae35a [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: read pas-id-fc1e4c9beb6ea2c066c359cf7dd241608a3ae35a: <<okay>> [DEBUG 00:02:13] eds_contact: requested 9, retrieved 10 from DB in 1 queries, misses 0/9 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-2fbd36fd668e3b67019338b0b250e154423ebf30-pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044 [DEBUG 00:02:13] eds_contact: reading: read pas-id-ff6140c178302b2caf5d5ee294c6811f63c5f044: <<okay>> [DEBUG 00:02:13] eds_contact: requested 10, retrieved 10 from DB in 1 queries, misses 0/10 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: set order 'none', 0 luids [DEBUG 00:02:13] ClientTest.cpp:857: ending CPPUNIT_ASSERT_EQUAL((0),(config.m_dump(client, *source.get(), sourceFile))) [DEBUG 00:02:13] ClientTest.cpp:857: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:13] ClientTest.cpp:857: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:13] ClientTest.cpp:858: starting source.reset() [DEBUG 00:02:13] ClientTest.cpp:454: starting CPPUNIT_ASSERT(get()) [DEBUG 00:02:13] ClientTest.cpp:454: ending CPPUNIT_ASSERT(get()) [DEBUG 00:02:13] ClientTest.cpp:455: starting CPPUNIT_ASSERT(m_active) [DEBUG 00:02:13] ClientTest.cpp:455: ending CPPUNIT_ASSERT(m_active) [DEBUG 00:02:13] ClientTest.cpp:458: starting get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:02:13] ClientTest.cpp:458: ending get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:02:13] ClientTest.cpp:461: starting anchor = get()->endSync(true) [DEBUG 00:02:13] ClientTest.cpp:461: ending anchor = get()->endSync(true) [DEBUG 00:02:13] ClientTest.cpp:463: starting get()->close() [DEBUG 00:02:13] ClientTest.cpp:463: ending get()->close() [DEBUG 00:02:13] ClientTest.cpp:858: ending source.reset() [DEBUG 00:02:13] ClientTest.cpp:391: starting reset(__null) [DEBUG 00:02:13] ClientTest.cpp:391: ending reset(__null) [DEBUG 00:02:13] ClientTest.cpp:863: starting CPPUNIT_ASSERT_EQUAL((0),(config.m_dump(client, copy, copyFile))) [DEBUG 00:02:13] ClientTest.cpp:6698: starting CPPUNIT_ASSERT(source.getOperations().m_backupData) [DEBUG 00:02:13] ClientTest.cpp:6698: ending CPPUNIT_ASSERT(source.getOperations().m_backupData) [DEBUG 00:02:13] eds_contact: reading: set order 'selected', 10 luids [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-22229b82b038c9c40cd242882d696d79186215a9 [DEBUG 00:02:13] eds_contact: reading: must read contact pas-id-22229b82b038c9c40cd242882d696d79186215a9 [DEBUG 00:02:13] eds_contact: reading: started contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: in running cache [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) finished: <<successful>> [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) got pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) got pas-id-db3584e5ccdea42d63ea3aaa84afbde8a110e216 [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) got pas-id-cc2cd48725f0372d41a3ec2fe1e8d37ffcca261d [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) got pas-id-b8afb20b5165f501622a8c86d54ab98313535b57 [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) got pas-id-b01afb80b852870fa76274c23867429b64dcb591 [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) got pas-id-88eae0a6817179f096bb718dd0c112e06d735a7d [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) got pas-id-6282a682e0e9ce27c5061d09a5f388e3ab3a58cc [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) got pas-id-61f2e84126ebd427e7d4393750dd834cb4ca9000 [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) got pas-id-56783f5f57c26ff9b0eb8562aff0ac0ede022914 [DEBUG 00:02:13] eds_contact: reading: contact read pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) got pas-id-22229b82b038c9c40cd242882d696d79186215a9 [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: read pas-id-22229b82b038c9c40cd242882d696d79186215a9: <<okay>> [DEBUG 00:02:13] eds_contact: requested 1, retrieved 10 from DB in 1 queries, misses 0/1 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-56783f5f57c26ff9b0eb8562aff0ac0ede022914 [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: read pas-id-56783f5f57c26ff9b0eb8562aff0ac0ede022914: <<okay>> [DEBUG 00:02:13] eds_contact: requested 2, retrieved 10 from DB in 1 queries, misses 0/2 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-61f2e84126ebd427e7d4393750dd834cb4ca9000 [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: read pas-id-61f2e84126ebd427e7d4393750dd834cb4ca9000: <<okay>> [DEBUG 00:02:13] eds_contact: requested 3, retrieved 10 from DB in 1 queries, misses 0/3 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-6282a682e0e9ce27c5061d09a5f388e3ab3a58cc [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: read pas-id-6282a682e0e9ce27c5061d09a5f388e3ab3a58cc: <<okay>> [DEBUG 00:02:13] eds_contact: requested 4, retrieved 10 from DB in 1 queries, misses 0/4 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-88eae0a6817179f096bb718dd0c112e06d735a7d [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: read pas-id-88eae0a6817179f096bb718dd0c112e06d735a7d: <<okay>> [DEBUG 00:02:13] eds_contact: requested 5, retrieved 10 from DB in 1 queries, misses 0/5 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-b01afb80b852870fa76274c23867429b64dcb591 [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: read pas-id-b01afb80b852870fa76274c23867429b64dcb591: <<okay>> [DEBUG 00:02:13] eds_contact: requested 6, retrieved 10 from DB in 1 queries, misses 0/6 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-b8afb20b5165f501622a8c86d54ab98313535b57 [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: read pas-id-b8afb20b5165f501622a8c86d54ab98313535b57: <<okay>> [DEBUG 00:02:13] eds_contact: requested 7, retrieved 10 from DB in 1 queries, misses 0/7 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-cc2cd48725f0372d41a3ec2fe1e8d37ffcca261d [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: read pas-id-cc2cd48725f0372d41a3ec2fe1e8d37ffcca261d: <<okay>> [DEBUG 00:02:13] eds_contact: requested 8, retrieved 10 from DB in 1 queries, misses 0/8 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-db3584e5ccdea42d63ea3aaa84afbde8a110e216 [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: read pas-id-db3584e5ccdea42d63ea3aaa84afbde8a110e216: <<okay>> [DEBUG 00:02:13] eds_contact: requested 9, retrieved 10 from DB in 1 queries, misses 0/9 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: getting contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: active cache pas-id-22229b82b038c9c40cd242882d696d79186215a9-pas-id-e2ee446f743c7907216991bea13b378fa27ca58d (10) [DEBUG 00:02:13] eds_contact: reading: in loaded cache [DEBUG 00:02:13] eds_contact: reading: in cache, available [DEBUG 00:02:13] eds_contact: reading: continue after contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [DEBUG 00:02:13] eds_contact: reading: read pas-id-e2ee446f743c7907216991bea13b378fa27ca58d: <<okay>> [DEBUG 00:02:13] eds_contact: requested 10, retrieved 10 from DB in 1 queries, misses 0/10 (0%), stalls 1 [DEBUG 00:02:13] eds_contact: reading: set order 'none', 0 luids [DEBUG 00:02:13] ClientTest.cpp:863: ending CPPUNIT_ASSERT_EQUAL((0),(config.m_dump(client, copy, copyFile))) [DEBUG 00:02:13] ClientTest.cpp:871: starting equal = config.m_compare(client, refFile.c_str(), actualFile.c_str()) [DEBUG 00:02:13] ClientTest.cpp:871: ending equal = config.m_compare(client, refFile.c_str(), actualFile.c_str()) [DEBUG 00:02:13] ClientTest.cpp:872: starting CPPUNIT_ASSERT(!raiseAssert || equal) [DEBUG 00:02:13] ClientTest.cpp:872: ending CPPUNIT_ASSERT(!raiseAssert || equal) [DEBUG 00:02:13] ClientTest.cpp:3084: starting copy.reset() [DEBUG 00:02:13] ClientTest.cpp:454: starting CPPUNIT_ASSERT(get()) [DEBUG 00:02:13] ClientTest.cpp:454: ending CPPUNIT_ASSERT(get()) [DEBUG 00:02:13] ClientTest.cpp:455: starting CPPUNIT_ASSERT(m_active) [DEBUG 00:02:13] ClientTest.cpp:455: ending CPPUNIT_ASSERT(m_active) [DEBUG 00:02:13] ClientTest.cpp:458: starting get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:02:13] ClientTest.cpp:458: ending get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:02:13] ClientTest.cpp:461: starting anchor = get()->endSync(true) [DEBUG 00:02:13] ClientTest.cpp:461: ending anchor = get()->endSync(true) [DEBUG 00:02:13] ClientTest.cpp:463: starting get()->close() [DEBUG 00:02:13] ClientTest.cpp:463: ending get()->close() [DEBUG 00:02:13] ClientTest.cpp:3084: ending copy.reset() [DEBUG 00:02:13] ClientTest.cpp:391: starting reset(__null) [DEBUG 00:02:13] ClientTest.cpp:391: ending reset(__null) [DEBUG 00:02:13] ClientTest.cpp:3086: starting CPPUNIT_ASSERT(it1 == sources.end()) [DEBUG 00:02:13] ClientTest.cpp:3086: ending CPPUNIT_ASSERT(it1 == sources.end()) [DEBUG 00:02:13] ClientTest.cpp:3087: starting CPPUNIT_ASSERT(it2 == accessClientB->sources.end()) [DEBUG 00:02:13] ClientTest.cpp:3087: ending CPPUNIT_ASSERT(it2 == accessClientB->sources.end()) [DEBUG 00:02:13] ClientTest.cpp:3089: starting CPPUNIT_ASSERT(!raiseAssert || equal) [DEBUG 00:02:13] ClientTest.cpp:3089: ending CPPUNIT_ASSERT(!raiseAssert || equal) [DEBUG 00:02:13] ClientTest.cpp:4651: ending compareDatabases() [DEBUG 00:02:13] ClientTest.cpp:4654: starting allSourcesDeleteAll() [DEBUG 00:02:13] ClientTest.cpp:6491: starting source_pair.second->deleteAll(source_pair.second->createSourceA) [DEBUG 00:02:13] ClientTest.cpp:802: starting CPPUNIT_ASSERT(createSource.createSource) [DEBUG 00:02:13] ClientTest.cpp:802: ending CPPUNIT_ASSERT(createSource.createSource) [DEBUG 00:02:13] ClientTest.cpp:807: starting source.reset(createSource()) [DEBUG 00:02:13] instantiating testing source eds_contact in config target-config@client-test-edsdav, with tracking name _1_A [DEBUG 00:02:13] overriding testing source eds_contact properties with the ones from config edsdav_1 = /data/runtests/work/testing-amd64/home/edsdav/config/syncevolution/client-test-edsdav-1/peers/edsdav_1 [DEBUG 00:02:13] sync = two-way (set) [DEBUG 00:02:13] uri = addressbook (set) [DEBUG 00:02:13] backend = Evolution Address Book (set) [DEBUG 00:02:13] syncFormat = (default) [DEBUG 00:02:13] forceSyncFormat = 0 (default) [DEBUG 00:02:13] database = Test_eds_contact_1 (set) [DEBUG 00:02:13] databaseFormat = (default) [DEBUG 00:02:13] databaseUser = (default) [DEBUG 00:02:13] databasePassword = (default) [DEBUG 00:02:13] ClientTest.cpp:424: starting CPPUNIT_ASSERT(get()) [DEBUG 00:02:13] ClientTest.cpp:424: ending CPPUNIT_ASSERT(get()) [DEBUG 00:02:13] ClientTest.cpp:425: starting CPPUNIT_ASSERT(!m_active) [DEBUG 00:02:13] ClientTest.cpp:425: ending CPPUNIT_ASSERT(!m_active) [DEBUG 00:02:13] ClientTest.cpp:431: starting get()->open() [DEBUG 00:02:13] ClientTest.cpp:431: ending get()->open() [DEBUG 00:02:13] eds_contact: using full item scan to detect changes [DEBUG 00:02:14] ClientTest.cpp:807: ending source.reset(createSource()) [DEBUG 00:02:14] ClientTest.cpp:807: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:14] ClientTest.cpp:807: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:14] ClientTest.cpp:810: starting source->removeAllItems() [DEBUG 00:02:14] ClientTest.cpp:810: ending source->removeAllItems() [DEBUG 00:02:14] ClientTest.cpp:810: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:14] ClientTest.cpp:810: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:14] ClientTest.cpp:811: starting source.reset() [DEBUG 00:02:14] ClientTest.cpp:454: starting CPPUNIT_ASSERT(get()) [DEBUG 00:02:14] ClientTest.cpp:454: ending CPPUNIT_ASSERT(get()) [DEBUG 00:02:14] ClientTest.cpp:455: starting CPPUNIT_ASSERT(m_active) [DEBUG 00:02:14] ClientTest.cpp:455: ending CPPUNIT_ASSERT(m_active) [DEBUG 00:02:14] ClientTest.cpp:458: starting get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:02:15] ClientTest.cpp:458: ending get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:02:15] ClientTest.cpp:461: starting anchor = get()->endSync(true) [DEBUG 00:02:15] ClientTest.cpp:461: ending anchor = get()->endSync(true) [DEBUG 00:02:15] ClientTest.cpp:463: starting get()->close() [DEBUG 00:02:15] ClientTest.cpp:463: ending get()->close() [DEBUG 00:02:15] ClientTest.cpp:811: ending source.reset() [DEBUG 00:02:15] ClientTest.cpp:814: starting source.reset(createSource()) [DEBUG 00:02:15] instantiating testing source eds_contact in config target-config@client-test-edsdav, with tracking name _1_A [DEBUG 00:02:15] overriding testing source eds_contact properties with the ones from config edsdav_1 = /data/runtests/work/testing-amd64/home/edsdav/config/syncevolution/client-test-edsdav-1/peers/edsdav_1 [DEBUG 00:02:15] sync = two-way (set) [DEBUG 00:02:15] uri = addressbook (set) [DEBUG 00:02:15] backend = Evolution Address Book (set) [DEBUG 00:02:15] syncFormat = (default) [DEBUG 00:02:15] forceSyncFormat = 0 (default) [DEBUG 00:02:15] database = Test_eds_contact_1 (set) [DEBUG 00:02:15] databaseFormat = (default) [DEBUG 00:02:15] databaseUser = (default) [DEBUG 00:02:15] databasePassword = (default) [DEBUG 00:02:15] ClientTest.cpp:424: starting CPPUNIT_ASSERT(get()) [DEBUG 00:02:15] ClientTest.cpp:424: ending CPPUNIT_ASSERT(get()) [DEBUG 00:02:15] ClientTest.cpp:425: starting CPPUNIT_ASSERT(!m_active) [DEBUG 00:02:15] ClientTest.cpp:425: ending CPPUNIT_ASSERT(!m_active) [DEBUG 00:02:15] ClientTest.cpp:431: starting get()->open() [DEBUG 00:02:15] ClientTest.cpp:431: ending get()->open() [DEBUG 00:02:15] eds_contact: using full item scan to detect changes [DEBUG 00:02:15] ClientTest.cpp:814: ending source.reset(createSource()) [DEBUG 00:02:15] ClientTest.cpp:814: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:15] ClientTest.cpp:814: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:15] ClientTest.cpp:818: starting CPPUNIT_ASSERT_MESSAGE(("should be empty now"), ((countItems(source.get()) == 0))) [DEBUG 00:02:15] ClientTest.cpp:818: ending CPPUNIT_ASSERT_MESSAGE(("should be empty now"), ((countItems(source.get()) == 0))) [DEBUG 00:02:15] ClientTest.cpp:818: starting CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:15] ClientTest.cpp:818: ending CPPUNIT_ASSERT((source.get())) [DEBUG 00:02:15] ClientTest.cpp:819: starting CPPUNIT_ASSERT_EQUAL((0),(countNewItems(source.get()))) [DEBUG 00:02:15] ClientTest.cpp:819: ending CPPUNIT_ASSERT_EQUAL((0),(countNewItems(source.get()))) [DEBUG 00:02:15] ClientTest.cpp:820: starting CPPUNIT_ASSERT_EQUAL((0),(countUpdatedItems(source.get()))) [DEBUG 00:02:15] ClientTest.cpp:820: ending CPPUNIT_ASSERT_EQUAL((0),(countUpdatedItems(source.get()))) [DEBUG 00:02:15] ClientTest.cpp:821: starting CPPUNIT_ASSERT_EQUAL((0),(countDeletedItems(source.get()))) [DEBUG 00:02:15] ClientTest.cpp:821: ending CPPUNIT_ASSERT_EQUAL((0),(countDeletedItems(source.get()))) [DEBUG 00:02:15] ClientTest.cpp:391: starting reset(__null) [DEBUG 00:02:15] ClientTest.cpp:454: starting CPPUNIT_ASSERT(get()) [DEBUG 00:02:15] ClientTest.cpp:454: ending CPPUNIT_ASSERT(get()) [DEBUG 00:02:15] ClientTest.cpp:455: starting CPPUNIT_ASSERT(m_active) [DEBUG 00:02:15] ClientTest.cpp:455: ending CPPUNIT_ASSERT(m_active) [DEBUG 00:02:15] ClientTest.cpp:458: starting get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:02:15] ClientTest.cpp:458: ending get()->getOperations().m_endDataWrite.getPostSignal()(*get(), OPERATION_FINISHED, sysync::LOCERR_OK, true, &dummy) [DEBUG 00:02:15] ClientTest.cpp:461: starting anchor = get()->endSync(true) [DEBUG 00:02:15] ClientTest.cpp:461: ending anchor = get()->endSync(true) [DEBUG 00:02:15] ClientTest.cpp:463: starting get()->close() [DEBUG 00:02:15] ClientTest.cpp:463: ending get()->close() [DEBUG 00:02:15] ClientTest.cpp:391: ending reset(__null) [DEBUG 00:02:15] ClientTest.cpp:6491: ending source_pair.second->deleteAll(source_pair.second->createSourceA) [DEBUG 00:02:15] ClientTest.cpp:4654: ending allSourcesDeleteAll() [DEBUG 00:02:15] ClientTest.cpp:4655: starting doSync(logPrefix, options) [DEBUG 00:02:15] 6. starting Client_Sync_eds_contact_testManyDeletes.delete-server.client.A with sync mode two-way [DEBUG 00:02:15] ClientTest.cpp:6460: starting res = client.doSync(sourceArray, logname, options) [DEBUG 00:02:15] log path -> /data/runtests/work/testing-amd64/home/edsdav/cache/syncevolution, No such file or directory [DEBUG 00:02:15] log path -> Client_Sync_eds_contact_testManyDeletes.delete-server.client.A, No such file or directory [DEBUG 00:02:15] log path -> Client_Sync_eds_contact_testManyDeletes.delete-server.client.A, No such file or directory [DEBUG 00:02:15] checking log dir Client_Sync_eds_contact_testManyDeletes.delete-server.client.A [DEBUG 00:02:15] logfile: Client_Sync_eds_contact_testManyDeletes.delete-server.client.A/syncevolution-log.html [DEVELOPER 00:02:17] SyncML server account: user01 [DEVELOPER 00:02:17] client: SyncEvolution 1.5.3 for workstation [DEVELOPER 00:02:17] device ID: client-edsdav_1 [DEVELOPER 00:02:17] [DEVELOPER 00:02:17] [INFO 00:02:17] addressbook: inactive [INFO 00:02:17] calendar: inactive [INFO 00:02:17] calendar+todo: inactive [INFO 00:02:17] eas_contact: inactive [INFO 00:02:17] eas_event: inactive [INFO 00:02:17] eas_memo: inactive [INFO 00:02:17] eas_task: inactive [INFO 00:02:17] eds_event: inactive [INFO 00:02:17] eds_memo: inactive [INFO 00:02:17] eds_task: inactive [INFO 00:02:17] file_calendar+todo: inactive [INFO 00:02:17] file_contact: inactive [INFO 00:02:17] file_event: inactive [INFO 00:02:17] file_task: inactive [INFO 00:02:17] kde_contact: inactive [INFO 00:02:17] kde_event: inactive [INFO 00:02:17] kde_memo: inactive [INFO 00:02:17] kde_task: inactive [INFO 00:02:17] memo: inactive [INFO 00:02:17] todo: inactive [DEBUG 00:02:17] checking password property 'password' in config 'edsdav_1@client-test-edsdav-1' with user identity 'user01' [DEBUG 00:02:17] loading password from keyring with key user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:02:17] not using KWallet [DEBUG 00:02:17] sync password for edsdav_1@client-test-edsdav-1: loaded password from GNOME keyring using user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:02:17] checking password property 'databasePassword' in datastore 'eds_contact' of config 'edsdav_1@client-test-edsdav-1' with user identity '' [DEBUG 00:02:17] sync is starting, catch signals [DEBUG 00:02:17] SuspendFlags: (re)activating, currently inactive [DEBUG 00:02:17] SuspendFlags: activating signal handler(s) with fds 38->37 [DEBUG 00:02:17] SuspendFlags: catch signal 15 [DEBUG 00:02:17] ready to sync [DEBUG 00:02:18] CreateContext SyncEvolution//eds_contact => 0 [DEBUG 00:02:18] Module_Version = 01090100 [DEBUG 00:02:18] Module_Capabilities: [DEBUG 00:02:18] PLATFORM:Linux [DEBUG 00:02:18] DLL:true [DEBUG 00:02:18] MINVERSION:V1.0.6.0 [DEBUG 00:02:18] MANUFACTURER:SyncEvolution [DEBUG 00:02:18] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:02:18] plugin_datastore_str:no [DEBUG 00:02:18] plugin_datastore_key:yes [DEBUG 00:02:18] ITEM_AS_KEY:yes [DEBUG 00:02:18] plugin_datablob:no [DEBUG 00:02:18] eds_contact: Module_PluginParams [DEBUG 00:02:18] eds_contact: Engine=01090100 [DEBUG 00:02:18] eds_contact: [DEBUG 00:02:18] Module_Capabilities: [DEBUG 00:02:18] PLATFORM:Linux [DEBUG 00:02:18] DLL:true [DEBUG 00:02:18] MINVERSION:V1.0.6.0 [DEBUG 00:02:18] MANUFACTURER:SyncEvolution [DEBUG 00:02:18] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:02:18] plugin_datastore_str:no [DEBUG 00:02:18] plugin_datastore_key:yes [DEBUG 00:02:18] ITEM_AS_KEY:yes [DEBUG 00:02:18] plugin_datablob:no [DEBUG 00:02:18] copying syncURL, username, password to Synthesis engine [DEBUG 00:02:18] using plain username/password for user01 [DEBUG 00:02:18] eds_contact: total number of items received 0 [INFO 00:02:34] eds_contact: starting normal sync, two-way (peer is server) [DEBUG 00:02:34] reading: set read-ahead based on sync mode two-way [DEBUG 00:02:34] eds_contact: reading: set order 'changed', 0 luids [DEBUG 00:02:34] eds_contact: 'eds_contact' dev='anydevice' usr='singleuser' err=0 [DEBUG 00:02:34] eds_contact: FilterSupport staticfilter: [DEBUG 00:02:34] eds_contact: dynamicfilter: [DEBUG 00:02:34] eds_contact: invisiblefilter: [DEBUG 00:02:34] eds_contact: using full item scan to detect changes [DEBUG 00:02:34] eds_contact: StartDataRead last='1' resume='1' res=0 [DEBUG 00:02:34] eds_contact: ReadNextItemAsKey aStatus=0 aID=((null),(null)) res=0 [DEBUG 00:02:34] eds_contact: EndDataRead res=0 [DEBUG 00:02:34] eds_contact: StartDataWrite [DEBUG 00:02:34] eds_contact: total number of items received 0 [INFO 00:02:34] eds_contact: sent 10/10 [INFO 00:02:36] eds_contact: started [DEBUG 00:02:36] eds_contact: total number of items received 0 [DEBUG 00:02:37] eds_contact: EndDataWrite COMMIT '1' res=0 [DEBUG 00:02:37] eds_contact: DeleteContext [INFO 00:02:37] eds_contact: normal sync done successfully [DEBUG 00:02:37] closing session [DEBUG 00:02:37] session closed [DEBUG 00:02:37] SuspendFlags: deactivating fds 38->37 [DEBUG 00:02:37] SuspendFlags: close m_receiverFD 37 [DEBUG 00:02:37] SuspendFlags: close m_senderFD 38 [DEBUG 00:02:37] SuspendFlags: done with deactivation [DEBUG 00:02:37] Module_DeleteContext eds_contact [INFO 00:02:37] sync report: [INFO 00:02:37] +---------------|-----------------------|-----------------------|-CON-+ [INFO 00:02:37] | | LOCAL | REMOTE | FLI | [INFO 00:02:37] | Source | NEW | MOD | DEL | ERR | NEW | MOD | DEL | ERR | CTS | [INFO 00:02:37] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:02:37] | eds_contact | 0 | 0 | 0 | 0 | 0 | 0 | 10 | 0 | 0 | [INFO 00:02:37] | two-way, 0 KB sent by client, 0 KB received | [INFO 00:02:37] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:02:37] | start Fri Jan 5 19:02:30 2018, duration 0:22min | [INFO 00:02:37] | synchronization completed successfully | [INFO 00:02:37] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:02:37] ----------|--------CLIENT---------|--------SERVER---------| [INFO 00:02:37] | NEW | MOD | DEL | NEW | MOD | DEL | [INFO 00:02:37] ----------|-----------------------------------------------| [INFO 00:02:37] Expected | 0 | 0 | 0 | 0 | 0 | 10 | [INFO 00:02:37] Expected sync mode: two-way [INFO 00:02:37] Expected cycles: 1 [INFO 00:02:37] [DEBUG 00:02:37] ClientTest.cpp:8283: starting CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:02:37] ClientTest.cpp:8283: ending CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:02:37] ClientTest.cpp:8284: starting CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:02:37] ClientTest.cpp:8284: ending CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:02:37] Checking sync source eds_contact... [DEBUG 00:02:37] ClientTest.cpp:8293: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:02:37] ClientTest.cpp:8293: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:02:37] ClientTest.cpp:8305: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:37] ClientTest.cpp:8305: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:37] ClientTest.cpp:8308: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:37] ClientTest.cpp:8308: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:37] ClientTest.cpp:8319: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:02:37] ClientTest.cpp:8319: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:02:37] ClientTest.cpp:8322: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:02:37] ClientTest.cpp:8322: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:02:37] ClientTest.cpp:8328: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(clientAdded),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8328: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(clientAdded),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8334: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8334: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8340: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(clientDeleted),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8340: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(clientDeleted),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8347: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8347: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8353: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8353: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8359: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(serverDeleted),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] ClientTest.cpp:8359: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(serverDeleted),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:37] Done with checking sync report. [DEBUG 00:02:37] ClientTest.cpp:6460: ending res = client.doSync(sourceArray, logname, options) [DEBUG 00:02:37] ClientTest.cpp:6465: starting postSync(res, logname) [DEBUG 00:02:37] ClientTest.cpp:6465: ending postSync(res, logname) [DEBUG 00:02:37] ClientTest.cpp:4655: ending doSync(logPrefix, options) [DEBUG 00:02:37] ClientTest.cpp:4666: starting doSync(logPrefix, options) [DEBUG 00:02:37] 7. starting Client_Sync_eds_contact_testManyDeletes.delete-client.client.B with sync mode refresh-from-server [DEBUG 00:02:37] ClientTest.cpp:6460: starting res = client.doSync(sourceArray, logname, options) [DEBUG 00:02:37] log path -> /data/runtests/work/testing-amd64/home/edsdav/cache/syncevolution, No such file or directory [DEBUG 00:02:37] log path -> Client_Sync_eds_contact_testManyDeletes.delete-client.client.B, No such file or directory [DEBUG 00:02:37] log path -> Client_Sync_eds_contact_testManyDeletes.delete-client.client.B, No such file or directory [DEBUG 00:02:37] checking log dir Client_Sync_eds_contact_testManyDeletes.delete-client.client.B [DEBUG 00:02:37] logfile: Client_Sync_eds_contact_testManyDeletes.delete-client.client.B/syncevolution-log.html [DEVELOPER 00:02:39] SyncML server account: user01 [DEVELOPER 00:02:39] client: SyncEvolution 1.5.3 for workstation [DEVELOPER 00:02:39] device ID: client-edsdav_2 [DEVELOPER 00:02:39] [DEVELOPER 00:02:39] [INFO 00:02:39] addressbook: inactive [INFO 00:02:39] calendar: inactive [INFO 00:02:39] calendar+todo: inactive [INFO 00:02:39] eas_contact: inactive [INFO 00:02:39] eas_event: inactive [INFO 00:02:39] eas_memo: inactive [INFO 00:02:39] eas_task: inactive [INFO 00:02:39] eds_event: inactive [INFO 00:02:39] eds_memo: inactive [INFO 00:02:39] eds_task: inactive [INFO 00:02:39] file_calendar+todo: inactive [INFO 00:02:39] file_contact: inactive [INFO 00:02:39] file_event: inactive [INFO 00:02:39] file_task: inactive [INFO 00:02:39] kde_contact: inactive [INFO 00:02:39] kde_event: inactive [INFO 00:02:39] kde_memo: inactive [INFO 00:02:39] kde_task: inactive [INFO 00:02:39] memo: inactive [INFO 00:02:39] todo: inactive [DEBUG 00:02:39] checking password property 'password' in config 'edsdav_2@client-test-edsdav-2' with user identity 'user01' [DEBUG 00:02:39] loading password from keyring with key user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:02:39] not using KWallet [DEBUG 00:02:39] sync password for edsdav_2@client-test-edsdav-2: loaded password from GNOME keyring using user=user01 server=127.0.0.1:9904/syncevolution [DEBUG 00:02:39] checking password property 'databasePassword' in datastore 'eds_contact' of config 'edsdav_2@client-test-edsdav-2' with user identity '' [DEBUG 00:02:39] sync is starting, catch signals [DEBUG 00:02:39] SuspendFlags: (re)activating, currently inactive [DEBUG 00:02:39] SuspendFlags: activating signal handler(s) with fds 38->37 [DEBUG 00:02:39] SuspendFlags: catch signal 15 [DEBUG 00:02:39] ready to sync [DEBUG 00:02:40] CreateContext SyncEvolution//eds_contact => 0 [DEBUG 00:02:40] Module_Version = 01090100 [DEBUG 00:02:40] Module_Capabilities: [DEBUG 00:02:40] PLATFORM:Linux [DEBUG 00:02:40] DLL:true [DEBUG 00:02:40] MINVERSION:V1.0.6.0 [DEBUG 00:02:40] MANUFACTURER:SyncEvolution [DEBUG 00:02:40] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:02:40] plugin_datastore_str:no [DEBUG 00:02:40] plugin_datastore_key:yes [DEBUG 00:02:40] ITEM_AS_KEY:yes [DEBUG 00:02:40] plugin_datablob:no [DEBUG 00:02:40] eds_contact: Module_PluginParams [DEBUG 00:02:40] eds_contact: Engine=01090100 [DEBUG 00:02:40] eds_contact: [DEBUG 00:02:40] Module_Capabilities: [DEBUG 00:02:40] PLATFORM:Linux [DEBUG 00:02:40] DLL:true [DEBUG 00:02:40] MINVERSION:V1.0.6.0 [DEBUG 00:02:40] MANUFACTURER:SyncEvolution [DEBUG 00:02:40] DESCRIPTION:SyncEvolution Synthesis DB Plugin [DEBUG 00:02:40] plugin_datastore_str:no [DEBUG 00:02:40] plugin_datastore_key:yes [DEBUG 00:02:40] ITEM_AS_KEY:yes [DEBUG 00:02:40] plugin_datablob:no [DEBUG 00:02:40] copying syncURL, username, password to Synthesis engine [DEBUG 00:02:40] using plain username/password for user01 [DEBUG 00:02:40] eds_contact: total number of items received 0 [INFO 00:02:56] eds_contact: starting first time sync from server (peer is server) [DEBUG 00:02:56] reading: set read-ahead based on sync mode refresh-from-remote [DEBUG 00:02:56] eds_contact: reading: set order 'none', 0 luids [DEBUG 00:02:56] eds_contact: 'eds_contact' dev='anydevice' usr='singleuser' err=0 [DEBUG 00:02:56] eds_contact: FilterSupport staticfilter: [DEBUG 00:02:56] eds_contact: dynamicfilter: [DEBUG 00:02:56] eds_contact: invisiblefilter: [DEBUG 00:02:56] eds_contact: ContextSupport ReadNextItem:allfields [DEBUG 00:02:56] eds_contact: [DEBUG 00:02:56] eds_contact: slow sync or testing, do full item scan to detect changes [DEBUG 00:02:56] eds_contact: StartDataRead last='' resume='' res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-22229b82b038c9c40cd242882d696d79186215a9,(null)) res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-56783f5f57c26ff9b0eb8562aff0ac0ede022914,(null)) res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-61f2e84126ebd427e7d4393750dd834cb4ca9000,(null)) res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-6282a682e0e9ce27c5061d09a5f388e3ab3a58cc,(null)) res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-88eae0a6817179f096bb718dd0c112e06d735a7d,(null)) res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-b01afb80b852870fa76274c23867429b64dcb591,(null)) res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-b8afb20b5165f501622a8c86d54ab98313535b57,(null)) res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-cc2cd48725f0372d41a3ec2fe1e8d37ffcca261d,(null)) res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-db3584e5ccdea42d63ea3aaa84afbde8a110e216,(null)) res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=2 aID=(pas-id-e2ee446f743c7907216991bea13b378fa27ca58d,(null)) res=0 [DEBUG 00:02:56] eds_contact: ReadNextItemAsKey aStatus=0 aID=((null),(null)) res=0 [DEBUG 00:02:56] eds_contact: EndDataRead res=0 [DEBUG 00:02:56] eds_contact: StartDataWrite [DEBUG 00:02:56] eds_contact: DeleteSyncSet not implemented [DEBUG 00:02:56] eds_contact: reading: getting contact pas-id-22229b82b038c9c40cd242882d696d79186215a9 [INFO 00:02:56] eds_contact: deleting "008- Doe" [DEBUG 00:02:56] eds_contact: DeleteItem aID=(pas-id-22229b82b038c9c40cd242882d696d79186215a9,) res=0 [DEBUG 00:02:56] eds_contact: reading: getting contact pas-id-56783f5f57c26ff9b0eb8562aff0ac0ede022914 [INFO 00:02:56] eds_contact: deleting "009- Doe" [DEBUG 00:02:56] eds_contact: DeleteItem aID=(pas-id-56783f5f57c26ff9b0eb8562aff0ac0ede022914,) res=0 [DEBUG 00:02:56] eds_contact: reading: getting contact pas-id-61f2e84126ebd427e7d4393750dd834cb4ca9000 [INFO 00:02:56] eds_contact: deleting "005- Doe" [DEBUG 00:02:56] eds_contact: DeleteItem aID=(pas-id-61f2e84126ebd427e7d4393750dd834cb4ca9000,) res=0 [DEBUG 00:02:56] eds_contact: reading: getting contact pas-id-6282a682e0e9ce27c5061d09a5f388e3ab3a58cc [INFO 00:02:56] eds_contact: deleting "001- Doe" [DEBUG 00:02:56] eds_contact: DeleteItem aID=(pas-id-6282a682e0e9ce27c5061d09a5f388e3ab3a58cc,) res=0 [DEBUG 00:02:56] eds_contact: reading: getting contact pas-id-88eae0a6817179f096bb718dd0c112e06d735a7d [INFO 00:02:56] eds_contact: deleting "003- Doe" [DEBUG 00:02:56] eds_contact: DeleteItem aID=(pas-id-88eae0a6817179f096bb718dd0c112e06d735a7d,) res=0 [DEBUG 00:02:56] eds_contact: reading: getting contact pas-id-b01afb80b852870fa76274c23867429b64dcb591 [INFO 00:02:56] eds_contact: deleting "000- Doe" [DEBUG 00:02:56] eds_contact: DeleteItem aID=(pas-id-b01afb80b852870fa76274c23867429b64dcb591,) res=0 [DEBUG 00:02:56] eds_contact: reading: getting contact pas-id-b8afb20b5165f501622a8c86d54ab98313535b57 [INFO 00:02:56] eds_contact: deleting "006- Doe" [DEBUG 00:02:56] eds_contact: DeleteItem aID=(pas-id-b8afb20b5165f501622a8c86d54ab98313535b57,) res=0 [DEBUG 00:02:56] eds_contact: reading: getting contact pas-id-cc2cd48725f0372d41a3ec2fe1e8d37ffcca261d [INFO 00:02:56] eds_contact: deleting "002- Doe" [DEBUG 00:02:56] eds_contact: DeleteItem aID=(pas-id-cc2cd48725f0372d41a3ec2fe1e8d37ffcca261d,) res=0 [DEBUG 00:02:56] eds_contact: reading: getting contact pas-id-db3584e5ccdea42d63ea3aaa84afbde8a110e216 [INFO 00:02:56] eds_contact: deleting "007- Doe" [DEBUG 00:02:56] eds_contact: DeleteItem aID=(pas-id-db3584e5ccdea42d63ea3aaa84afbde8a110e216,) res=0 [DEBUG 00:02:56] eds_contact: reading: getting contact pas-id-e2ee446f743c7907216991bea13b378fa27ca58d [INFO 00:02:56] eds_contact: deleting "004- Doe" [DEBUG 00:02:56] eds_contact: DeleteItem aID=(pas-id-e2ee446f743c7907216991bea13b378fa27ca58d,) res=0 [DEBUG 00:02:56] eds_contact: total number of items received 0 [INFO 00:02:56] eds_contact: deleting 10/10 [INFO 00:02:58] eds_contact: started [DEBUG 00:02:58] eds_contact: total number of items received 0 [DEBUG 00:02:59] eds_contact: EndDataWrite COMMIT '1' res=0 [DEBUG 00:02:59] eds_contact: DeleteContext [INFO 00:02:59] eds_contact: first time sync done successfully [DEBUG 00:02:59] closing session [DEBUG 00:02:59] session closed [DEBUG 00:02:59] SuspendFlags: deactivating fds 38->37 [DEBUG 00:02:59] SuspendFlags: close m_receiverFD 37 [DEBUG 00:02:59] SuspendFlags: close m_senderFD 38 [DEBUG 00:02:59] SuspendFlags: done with deactivation [DEBUG 00:02:59] Module_DeleteContext eds_contact [INFO 00:02:59] sync report: [INFO 00:02:59] +---------------|-----------------------|-----------------------|-CON-+ [INFO 00:02:59] | | LOCAL | REMOTE | FLI | [INFO 00:02:59] | Source | NEW | MOD | DEL | ERR | NEW | MOD | DEL | ERR | CTS | [INFO 00:02:59] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:02:59] | eds_contact | 0 | 0 | 10 | 0 | 0 | 0 | 0 | 0 | 0 | [INFO 00:02:59] | refresh-from-remote, 0 KB sent by client, 0 KB received | [INFO 00:02:59] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:02:59] | start Fri Jan 5 19:02:52 2018, duration 0:22min | [INFO 00:02:59] | synchronization completed successfully | [INFO 00:02:59] +---------------+-----+-----+-----+-----+-----+-----+-----+-----+-----+ [INFO 00:02:59] ----------|--------CLIENT---------|--------SERVER---------| [INFO 00:02:59] | NEW | MOD | DEL | NEW | MOD | DEL | [INFO 00:02:59] ----------|-----------------------------------------------| [INFO 00:02:59] Expected | 0 | 0 | 10 | 0 | 0 | 0 | [INFO 00:02:59] Expected sync mode: refresh-from-remote [INFO 00:02:59] Expected cycles: 1 [INFO 00:02:59] [DEBUG 00:02:59] ClientTest.cpp:8283: starting CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:02:59] ClientTest.cpp:8283: ending CPPUNIT_ASSERT_EQUAL((string("no error (remote, status 0)")),(Status2String(status))) [DEBUG 00:02:59] ClientTest.cpp:8284: starting CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:02:59] ClientTest.cpp:8284: ending CPPUNIT_ASSERT_EQUAL((STATUS_OK),(status)) [DEBUG 00:02:59] Checking sync source eds_contact... [DEBUG 00:02:59] ClientTest.cpp:8293: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:02:59] ClientTest.cpp:8293: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "STATUS_OK" + " == " + "source.getStatus()",(STATUS_OK),(source.getStatus())) [DEBUG 00:02:59] ClientTest.cpp:8305: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:59] ClientTest.cpp:8305: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:59] ClientTest.cpp:8308: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:59] ClientTest.cpp:8308: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "0" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT)",(0),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ANY, SyncSourceReport::ITEM_REJECT))) [DEBUG 00:02:59] ClientTest.cpp:8319: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:02:59] ClientTest.cpp:8319: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "syncMode" + " == " + "source.getFinalSyncMode()",(syncMode),(source.getFinalSyncMode())) [DEBUG 00:02:59] ClientTest.cpp:8322: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:02:59] ClientTest.cpp:8322: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "restarts + 1" + " == " + "source.getRestarts() + 1",(restarts + 1),(source.getRestarts() + 1)) [DEBUG 00:02:59] ClientTest.cpp:8328: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(clientAdded),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8328: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(clientAdded),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8334: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8334: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(clientUpdated),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8340: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(clientDeleted),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8340: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "clientDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(clientDeleted),(source.getItemStat(SyncSourceReport::ITEM_LOCAL, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8347: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8347: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverAdded" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL)",(serverAdded),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_ADDED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8353: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8353: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverUpdated" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL)",(serverUpdated),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_UPDATED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8359: starting CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(serverDeleted),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] ClientTest.cpp:8359: ending CPPUNIT_ASSERT_EQUAL_MESSAGE(std::string(name) + ": " + "serverDeleted" + " == " + "source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL)",(serverDeleted),(source.getItemStat(SyncSourceReport::ITEM_REMOTE, SyncSourceReport::ITEM_REMOVED, SyncSourceReport::ITEM_TOTAL))) [DEBUG 00:02:59] Done with checking sync report. [DEBUG 00:02:59] ClientTest.cpp:6460: ending res = client.doSync(sourceArray, logname, options) [DEBUG 00:02:59] ClientTest.cpp:6465: starting postSync(res, logname) [DEBUG 00:02:59] ClientTest.cpp:6465: ending postSync(res, logname) [DEBUG 00:02:59] ClientTest.cpp:4666: ending doSync(logPrefix, options) [DEBUG 00:02:59] *** ending Client::Sync::eds_contact::testManyDeletes: okay ***