See http://qa.nuxeo.org/jenkins/job/FT-nuxeo-drive-master-windows/555/consoleFull
01:23:14 [INFO] [exec] ====================================================================== 01:23:14 [INFO] [exec] FAIL: test_drive_edit_remote_move_sync_root_to_non_sync_root (nxdrive.tests.test_drive_edit.TestDriveEdit) 01:23:14 [INFO] [exec] ---------------------------------------------------------------------- 01:23:14 [INFO] [exec] Traceback (most recent call last): 01:23:14 [INFO] [exec] File "c:\hudson\workspace\FT-nuxeo-drive-master-windows\nuxeo-drive-client\nxdrive\tests\test_drive_edit.py", line 278, in test_drive_edit_remote_move_sync_root_to_non_sync_root 01:23:14 [INFO] [exec] % LOCALLY_EDITED_FOLDER_NAME)), 1) 01:23:14 [INFO] [exec] AssertionError: 2 != 1 01:23:14 [INFO] [exec] -------------------- >> begin captured logging << -------------------- 01:23:14 [INFO] [exec] nxdrive.controller: INFO: nxdrive installed in 'c:\hudson\workspace\FT-nuxeo-drive-master-windows\ftest\target\nxdrive_msi\SourceDir\appdata\nuxeo-drive-1.3.1216.win32\library.zip\nxdrive' 01:23:14 [INFO] [exec] nxdrive.controller: INFO: nxdrive configured in 'c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\nuxeo-drive-conf' 01:23:14 [INFO] [exec] alembic.migration: INFO: Context impl SQLiteImpl. 01:23:14 [INFO] [exec] alembic.migration: INFO: Will assume non-transactional DDL. 01:23:14 [INFO] [exec] nxdrive.migration: DEBUG: Checking if SQLite database migration is needed. 01:23:14 [INFO] [exec] nxdrive.migration: DEBUG: Head Alembic revision: 10eaff28d372 01:23:14 [INFO] [exec] nxdrive.migration: DEBUG: Alembic is not initialized, setting current revision to head revision: 10eaff28d372 01:23:14 [INFO] [exec] nxdrive.migration: DEBUG: Current Alembic revision: 10eaff28d372 01:23:14 [INFO] [exec] nxdrive.migration: DEBUG: No migration to process as current Alembic revision in SQLite database is already the head revision. 01:23:14 [INFO] [exec] nxdrive.model: DEBUG: Set client version to 1.3.1216 01:23:14 [INFO] [exec] nxdrive.controller: INFO: nxdrive installed in 'c:\hudson\workspace\FT-nuxeo-drive-master-windows\ftest\target\nxdrive_msi\SourceDir\appdata\nuxeo-drive-1.3.1216.win32\library.zip\nxdrive' 01:23:14 [INFO] [exec] nxdrive.controller: INFO: nxdrive configured in 'c:\users\nuxeo\appdata\local\temp\tmpmkx4ap-nxdrive-tests-user-2\nuxeo-drive-conf' 01:23:14 [INFO] [exec] alembic.migration: INFO: Context impl SQLiteImpl. 01:23:14 [INFO] [exec] alembic.migration: INFO: Will assume non-transactional DDL. 01:23:14 [INFO] [exec] nxdrive.migration: DEBUG: Checking if SQLite database migration is needed. 01:23:14 [INFO] [exec] nxdrive.migration: DEBUG: Head Alembic revision: 10eaff28d372 01:23:14 [INFO] [exec] nxdrive.migration: DEBUG: Alembic is not initialized, setting current revision to head revision: 10eaff28d372 01:23:14 [INFO] [exec] nxdrive.migration: DEBUG: Current Alembic revision: 10eaff28d372 01:23:14 [INFO] [exec] nxdrive.migration: DEBUG: No migration to process as current Alembic revision in SQLite database is already the head revision. 01:23:14 [INFO] [exec] nxdrive.model: DEBUG: Set client version to 1.3.1216 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3.1216', 'X-Device-Id': u'nxdrive-test-administrator-device', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'} and cookies [] 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"value": "/"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"6c67aad6-a422-4a86-8ac1-552babf02754","path":"/","type":"Root","state":null,"parentRef":"/","versionLabel":"","isCheckedOut":true,"title":"6c67aad6-a422-4a86-8ac1-552babf02754","properties":{"dc:creator":null,"dc:source":null,"dc:nature":null,"dc:contributors":[],"dc:created":null,"dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":null,"dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":null,"dc:lastContributor":null,"common:icon":null,"common:icon-expanded":null,"common:size":null},"facets":["Folderish","NotCollectionMember"],"changeToken":null,"contextParameters":{}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'userNames': 'user_1, user_2', 'permission': 'ReadWrite'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"userNames": "user_1, user_2", "permission": "ReadWrite"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests' with cookies [] has content-type 'text/plain' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/default-domain/workspaces/nuxeo-drive-test-workspace'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"value": "/default-domain/workspaces/nuxeo-drive-test-workspace"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"18b6d043-fec3-42c9-a66b-044a232a63cf","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"d04b591f-fb35-41c6-ba09-81e66defcc8f","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-12-16T00:16:14.20Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:nature":null,"dc:contributors":["Administrator"],"dc:created":"2014-12-16T00:16:14.20Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-16T00:16:14.20Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Nuxeo Drive Test Workspace","dc:lastContributor":"Administrator","files:files":[],"common:icon":"/icons/workspace.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"webc:welcomeText":null,"webc:useCaptcha":null,"webc:welcomeMedia":null,"webc:theme":"sites","webc:isWebContainer":null,"webc:baseline":null,"webc:template":null,"webc:logo":null,"webc:themePerspective":null,"webc:themePage":"workspace","webc:name":null,"webc:moderationType":"aposteriori","webc:url":null,"webc:email":null,"publish:sections":[]},"facets":["SuperSpace","Folderish"],"changeToken":"1418688974209","contextParameters":{}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3.1216', 'X-Device-Id': u'nxdrive-test-device-1', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI='} and cookies [] 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'18b6d043-fec3-42c9-a66b-044a232a63cf'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI='}, cookies [] and JSON payload '{"params": {"value": "18b6d043-fec3-42c9-a66b-044a232a63cf"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"18b6d043-fec3-42c9-a66b-044a232a63cf","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"d04b591f-fb35-41c6-ba09-81e66defcc8f","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-12-16T00:16:14.20Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:nature":null,"dc:contributors":["Administrator"],"dc:created":"2014-12-16T00:16:14.20Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-16T00:16:14.20Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Nuxeo Drive Test Workspace","dc:lastContributor":"Administrator","files:files":[],"common:icon":"/icons/workspace.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"webc:welcomeText":null,"webc:useCaptcha":null,"webc:welcomeMedia":null,"webc:theme":"sites","webc:isWebContainer":null,"webc:baseline":null,"webc:template":null,"webc:logo":null,"webc:themePerspective":null,"webc:themePage":"workspace","webc:name":null,"webc:moderationType":"aposteriori","webc:url":null,"webc:email":null,"publish:sections":[]},"facets":["SuperSpace","Folderish"],"changeToken":"1418688974209","contextParameters":{}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3.1216', 'X-Device-Id': u'nxdrive-test-device-2', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo4NWY1OTA='} and cookies [] 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'18b6d043-fec3-42c9-a66b-044a232a63cf'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-2', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo4NWY1OTA='}, cookies [] and JSON payload '{"params": {"value": "18b6d043-fec3-42c9-a66b-044a232a63cf"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"18b6d043-fec3-42c9-a66b-044a232a63cf","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"d04b591f-fb35-41c6-ba09-81e66defcc8f","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-12-16T00:16:14.20Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:nature":null,"dc:contributors":["Administrator"],"dc:created":"2014-12-16T00:16:14.20Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-16T00:16:14.20Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Nuxeo Drive Test Workspace","dc:lastContributor":"Administrator","files:files":[],"common:icon":"/icons/workspace.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"webc:welcomeText":null,"webc:useCaptcha":null,"webc:welcomeMedia":null,"webc:theme":"sites","webc:isWebContainer":null,"webc:baseline":null,"webc:template":null,"webc:logo":null,"webc:themePerspective":null,"webc:themePage":"workspace","webc:name":null,"webc:moderationType":"aposteriori","webc:url":null,"webc:email":null,"publish:sections":[]},"facets":["SuperSpace","Folderish"],"changeToken":"1418688974209","contextParameters":{}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3.1216', 'X-Device-Id': u'nxdrive-test-device-1', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI='} and cookies [] 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3.1216', 'X-Device-Id': u'nxdrive-test-device-2', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo4NWY1OTA='} and cookies [] 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3.1216', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI='} and cookies [] 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/authentication/token?applicationName=Nuxeo+Drive&deviceDescription=Windows+Desktop&revoke=false&deviceId=bef4f14f84b811e494290024e814f531&permission=ReadWrite with headers {'X-Client-Version': '1.3.1216', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI='} and cookies [] 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Got token 'ee141d43-bc34-4509-8732-f0f8dc21f711' with cookies [] 01:23:14 [INFO] [exec] nxdrive.controller: INFO: Binding 'c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive' to 'http://localhost:8080/nuxeo/' with account 'nuxeoDriveTestUser_user_1' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'} and cookies [] 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder' with cookies []: '{"canCreateChild":false,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","creationDate":474,"creator":"system","folder":true,"parentId":null,"canRename":false,"canDelete":false,"lastContributor":"system","lastModificationDate":474,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/', remote_name=None, local_state=None, remote_state=None, pair_state='unknown'> 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/', remote_name=u'Nuxeo Drive', local_state='unknown', remote_state='modified', pair_state='remotely_modified'> 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/', remote_name=u'Nuxeo Drive', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'> 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo' with cookies []: '{"serverVersion":"7.1-SNAPSHOT","updateSiteURL":"http://community.nuxeo.com/static/drive/"}' 01:23:14 [INFO] [exec] nxdrive.controller: INFO: Fetched update info from server: {u'serverVersion': u'7.1-SNAPSHOT', u'updateSiteURL': u'http://community.nuxeo.com/static/drive/'} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/', 'params': {'type': 'Folder', 'name': 'syncRoot', 'properties': 'dc:title=syncRoot'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/", "params": {"type": "Folder", "name": "syncRoot", "properties": "dc:title=syncRoot"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies []: '{"entity-type":"document","repository":"default","uid":"a6a56d11-1323-4b99-97ed-5ae4b2917e9c","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/syncRoot","type":"Folder","state":"project","parentRef":"18b6d043-fec3-42c9-a66b-044a232a63cf","versionLabel":"","isCheckedOut":true,"title":"syncRoot","lastModified":"2014-12-16T00:16:14.49Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2014-12-16T00:16:14.49Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-16T00:16:14.49Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"syncRoot","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1418688974490","contextParameters":{}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'} and cookies [] 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:a6a56d11-1323-4b99-97ed-5ae4b2917e9c', 'params': {'enable': True}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization with headers {'X-Authentication-Token': u'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"input": "doc:a6a56d11-1323-4b99-97ed-5ae4b2917e9c", "params": {"enable": true}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization' with cookies [] has content-type '' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:a6a56d11-1323-4b99-97ed-5ae4b2917e9c', 'params': {'type': 'File', 'name': 'test.odt', 'properties': 'dc:title=test.odt'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI='}, cookies [] and JSON payload '{"input": "doc:a6a56d11-1323-4b99-97ed-5ae4b2917e9c", "params": {"type": "File", "name": "test.odt", "properties": "dc:title=test.odt"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies []: '{"entity-type":"document","repository":"default","uid":"86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/syncRoot/test.odt","type":"File","state":"project","parentRef":"a6a56d11-1323-4b99-97ed-5ae4b2917e9c","versionLabel":"0.0","isCheckedOut":true,"title":"test.odt","lastModified":"2014-12-16T00:16:14.69Z","properties":{"uid:uid":null,"uid:minor_version":0,"uid:major_version":0,"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2014-12-16T00:16:14.69Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-16T00:16:14.69Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"test.odt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"common:icon":"/icons/file.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","Versionable","Publishable","HasRelatedText"],"changeToken":"1418688974693","contextParameters":{}}' 01:23:14 [INFO] [exec] nxdrive.utils: TRACE: Guessed mime type 'application/vnd.oasis.opendocument.text' for 'test.odt' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 13L, 'X-Client-Version': '1.3.1216', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'application/vnd.oasis.opendocument.text', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 13L, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1418688974.74_52596022', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'test.odt'} and cookies [] for file c:\users\nuxeo\appdata\local\temp\tmpmkpnqn-nxdrive-uploads\tmpezhijf-nxdrive-file-to-upload 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies []: '{"uploaded":"true","batchId":"1418688974.74_52596022"}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Using 300 seconds [max(300, 2 * upload time=0)] as Nuxeo transaction timeout for batch execution of Blob.Attach with file c:\users\nuxeo\appdata\local\temp\tmpmkpnqn-nxdrive-uploads\tmpezhijf-nxdrive-file-to-upload 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1418688974.74_52596022', 'document': u'86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'fileIdx': '0', 'operationId': 'Blob.Attach'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-Application-Name': 'Nuxeo Drive', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'Nuxeo-Transaction-Timeout': 300, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI='}, cookies [] and JSON payload '{"params": {"batchId": "1418688974.74_52596022", "document": "86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "fileIdx": "0", "operationId": "Blob.Attach"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] has content-type 'application/vnd.oasis.opendocument.text' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type '' 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=1600) 01:23:14 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Fetching remote change summary 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"activeSynchronizationRootDefinitions":"default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c","syncDate":1418688974000,"upperBound":872,"fileSystemChanges":[],"hasTooManyChanges":false}' 01:23:14 [INFO] [exec] nxdrive.client.remote_filtered_file_system_client: TRACE: result['hasTooManyChanges'] = False 01:23:14 [INFO] [exec] nxdrive.client.remote_filtered_file_system_client: TRACE: server_binding.last_filter_date = None 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote full scan of c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive. Reasons: forced: False, too many changes: False, first pass: True 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":false,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","creationDate":880,"creator":"system","folder":true,"parentId":null,"canRename":false,"canDelete":false,"lastContributor":"system","lastModificationDate":880,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"canCreateChild":true,"name":"syncRoot","id":"defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","creationDate":1418688974490,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688974662,"userName":"nuxeoDriveTestUser_user_1"}]' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'syncRoot', local_state=None, remote_state='modified', pair_state='unknown'> 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'syncRoot', local_state='unknown', remote_state='modified', pair_state='remotely_modified'> 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'syncRoot', local_state='unknown', remote_state='modified', pair_state='remotely_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"digest":"b8ab309a6b9a3f448092a136afa8fa25","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688974755,"userName":"nuxeoDriveTestUser_user_1"}]' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state=None, remote_state='modified', pair_state='unknown'> 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state='unknown', remote_state='modified', pair_state='remotely_modified'> 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state='unknown', remote_state='modified', pair_state='remotely_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Processing local scan to detect local changes 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 2 pending item(s) 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'syncRoot', local_state=u'unknown', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0>, LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state=u'unknown', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0>] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'syncRoot', local_state=u'unknown', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c', 'parentId': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c", "parentId": "org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":true,"name":"syncRoot","id":"defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","creationDate":1418688974490,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688974662,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'syncRoot', local_state=u'unknown', remote_state='created', pair_state='remotely_created'> 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_remotely_created of <nxdrive.synchronizer.Synchronizer object at 0x05BCD4D0>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'syncRoot', local_state=u'unknown', remote_state=u'created', pair_state=u'remotely_created', error_count=0> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local folder 'syncRoot' in 'c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\' 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of syncRoot 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"digest":"b8ab309a6b9a3f448092a136afa8fa25","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688974755,"userName":"nuxeoDriveTestUser_user_1"}]' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/syncRoot', remote_name=u'syncRoot', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'> 01:23:14 [INFO] [exec] nxdrive.controller: TRACE: Updated list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [] 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 1 pending item(s) 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state=u'unknown', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0>] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state=u'unknown', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'parentId': u'defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "parentId": "defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"b8ab309a6b9a3f448092a136afa8fa25","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688974755,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'> 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_remotely_created of <nxdrive.synchronizer.Synchronizer object at 0x05BCD4D0>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state=u'unknown', remote_state=u'created', pair_state=u'remotely_created', error_count=0> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local file 'test.odt' in 'c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\syncRoot' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'parentId': u'defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "parentId": "defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"b8ab309a6b9a3f448092a136afa8fa25","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688974755,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt' with headers: {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'} 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'> 01:23:14 [INFO] [exec] nxdrive.controller: TRACE: Updated list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [u'test.odt'] 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: [c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 2, pending: 2, local: 0.016s, remote: 0.093s sync: 0.140s 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 1 loops 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x06D90870>, ending any transaction in progress and releasing underlying connections from the pool 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: As we are under Windows, dispose connection pool to make sure all connections are closed, avoiding any WindowsError due to a Python process using the database file 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping all FS Observers thread 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'} and cookies [] 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: Local edition: filename = test.odt, unquoted filename = test.odt, quoted filename = test.odt 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: Downloading file 'test.odt' in '\\?\c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\Locally Edited' with URL 'http://localhost:8080/nuxeo/nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt' with headers: {'X-Authentication-Token': u'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'params': {}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.AddToLocallyEditedCollection with headers {'X-Authentication-Token': u'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"input": "doc:86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "params": {}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.AddToLocallyEditedCollection' with cookies []: '{"entity-type":"document","repository":"default","uid":"86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/syncRoot/test.odt","type":"File","state":"project","parentRef":"a6a56d11-1323-4b99-97ed-5ae4b2917e9c","versionLabel":"0.0","isCheckedOut":true,"title":"test.odt","lastModified":"2014-12-16T00:16:14.75Z","properties":{"uid:uid":null,"uid:minor_version":0,"uid:major_version":0,"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2014-12-16T00:16:14.69Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-16T00:16:14.75Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"test.odt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"thumb:thumbnail":{"name":"a296249f9b03952cc068c6c64965d9b5","mime-type":"application/octet-stream","encoding":null,"digest":"a296249f9b03952cc068c6c64965d9b5","length":"448","data":"http://localhost:8080/nuxeo/nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/thumbnail:thumb:thumbnail/a296249f9b03952cc068c6c64965d9b5"},"common:icon":"/icons/odt.png","common:icon-expanded":null,"common:size":13,"file:content":{"name":"test.odt","mime-type":"application/vnd.oasis.opendocument.text","encoding":null,"digest":"b8ab309a6b9a3f448092a136afa8fa25","length":"13","data":"http://localhost:8080/nuxeo/nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/file:content/test.odt"},"file:filename":null,"collectionMember:collectionIds":[],"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","CollectionMember","Versionable","Publishable","HasRelatedText","Thumbnail"],"changeToken":"1418688974755","contextParameters":{}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type '' 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=1600) 01:23:14 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [u'test.odt'] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Fetching remote change summary 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lowerBound': 872, 'lastSyncActiveRootDefinitions': u'default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"lowerBound": 872, "lastSyncActiveRootDefinitions": "default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"activeSynchronizationRootDefinitions":"default:8c8b872e-a51d-4073-b134-0b9bd3d9b115,default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c","syncDate":1418688975000,"upperBound":895,"fileSystemChanges":[{"eventId":"rootRegistered","fileSystemItemName":"Locally Edited","eventDate":1418688975286,"docUuid":"8c8b872e-a51d-4073-b134-0b9bd3d9b115","repositoryId":"default","fileSystemItem":{"canCreateChild":false,"name":"Locally Edited","id":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","creationDate":1418688975254,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688975286,"userName":"nuxeoDriveTestUser_user_1"},"fileSystemItemId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115"},{"eventId":"addedToCollection","fileSystemItemName":"test.odt","eventDate":1418688975270,"docUuid":"86d321c0-cdeb-4e6e-bfd6-6113dd50f433","repositoryId":"default","fileSystemItem":{"digest":"b8ab309a6b9a3f448092a136afa8fa25","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688974755,"userName":"nuxeoDriveTestUser_user_1"},"fileSystemItemId":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433"},{"eventId":"documentCreated","fileSystemItemName":"Locally Edited","eventDate":1418688975254,"docUuid":"8c8b872e-a51d-4073-b134-0b9bd3d9b115","repositoryId":"default","fileSystemItem":{"canCreateChild":false,"name":"Locally Edited","id":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","creationDate":1418688975254,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688975286,"userName":"nuxeoDriveTestUser_user_1"},"fileSystemItemId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115"},{"eventId":"documentModified","fileSystemItemName":"Locally Edited","eventDate":1418688975254,"docUuid":"8c8b872e-a51d-4073-b134-0b9bd3d9b115","repositoryId":"default","fileSystemItem":{"canCreateChild":false,"name":"Locally Edited","id":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","creationDate":1418688975254,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688975286,"userName":"nuxeoDriveTestUser_user_1"},"fileSystemItemId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115"}],"hasTooManyChanges":false}' 01:23:14 [INFO] [exec] nxdrive.client.remote_filtered_file_system_client: TRACE: result['hasTooManyChanges'] = False 01:23:14 [INFO] [exec] nxdrive.client.remote_filtered_file_system_client: TRACE: server_binding.last_filter_date = None 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Updating remote states 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: 4 remote changes detected on http://localhost:8080/nuxeo/ 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'Locally Edited', local_state=None, remote_state='modified', pair_state='unknown'> 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'Locally Edited', local_state='unknown', remote_state='modified', pair_state='remotely_modified'> 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Locally Edited', local_state='unknown', remote_state='modified', pair_state='remotely_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Marked doc_pair 'Locally Edited' as remote creation 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Locally Edited 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"digest":"b8ab309a6b9a3f448092a136afa8fa25","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688974755,"userName":"nuxeoDriveTestUser_user_1"}]' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state=None, remote_state='modified', pair_state='unknown'> 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state='unknown', remote_state='modified', pair_state='remotely_modified'> 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state='unknown', remote_state='modified', pair_state='remotely_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Refreshing remote state info for doc_pair '/syncRoot/test.odt' 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Refreshing remote state info for doc_pair 'test.odt' 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Processing local scan to detect local changes 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Matched local /Locally Edited with remote Locally Edited by name only 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'Locally Edited', local_state='created', remote_state=u'modified', pair_state='conflicted'> 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=None, remote_name=u'test.odt', local_state='created', remote_state=u'modified', pair_state='conflicted'> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Matched local /Locally Edited/test.odt with remote test.odt with digest 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 2 pending item(s) 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Locally Edited', remote_name=u'Locally Edited', local_state=u'created', remote_state=u'modified', pair_state=u'conflicted', error_count=0>, LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state=u'created', remote_state=u'modified', pair_state=u'conflicted', error_count=0>] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Locally Edited', remote_name=u'Locally Edited', local_state=u'created', remote_state=u'modified', pair_state=u'conflicted', error_count=0> 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115', 'parentId': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115", "parentId": "org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":false,"name":"Locally Edited","id":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","creationDate":1418688975254,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688975286,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_conflicted of <nxdrive.synchronizer.Synchronizer object at 0x05BCD4D0>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Locally Edited', remote_name=u'Locally Edited', local_state=u'created', remote_state=u'modified', pair_state=u'conflicted', error_count=0> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Automated conflict resolution using name for c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\Locally Edited 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/Locally Edited', remote_name=u'Locally Edited', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'> 01:23:14 [INFO] [exec] nxdrive.controller: TRACE: Updated list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [u'test.odt'] 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 1 pending item(s) 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state=u'created', remote_state=u'modified', pair_state=u'conflicted', error_count=0>] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state=u'created', remote_state=u'modified', pair_state=u'conflicted', error_count=0> 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'parentId': u'collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "parentId": "collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"b8ab309a6b9a3f448092a136afa8fa25","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688974755,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_conflicted of <nxdrive.synchronizer.Synchronizer object at 0x05BCD4D0>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state=u'created', remote_state=u'modified', pair_state=u'conflicted', error_count=0> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Automated conflict resolution using digest for c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\Locally Edited\test.odt 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'> 01:23:14 [INFO] [exec] nxdrive.controller: TRACE: Updated list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [u'test.odt', u'test.odt'] 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: [c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 2, pending: 2, local: 0.031s, remote: 0.172s sync: 0.078s 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 1 loops 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x06D90870>, ending any transaction in progress and releasing underlying connections from the pool 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: As we are under Windows, dispose connection pool to make sure all connections are closed, avoiding any WindowsError due to a Python process using the database file 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping all FS Observers thread 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=1600) 01:23:14 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [u'test.odt', u'test.odt'] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Fetching remote change summary 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lowerBound': 895, 'lastSyncActiveRootDefinitions': u'default:8c8b872e-a51d-4073-b134-0b9bd3d9b115,default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"lowerBound": 895, "lastSyncActiveRootDefinitions": "default:8c8b872e-a51d-4073-b134-0b9bd3d9b115,default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"activeSynchronizationRootDefinitions":"default:8c8b872e-a51d-4073-b134-0b9bd3d9b115,default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c","syncDate":1418688976000,"upperBound":898,"fileSystemChanges":[],"hasTooManyChanges":false}' 01:23:14 [INFO] [exec] nxdrive.client.remote_filtered_file_system_client: TRACE: result['hasTooManyChanges'] = False 01:23:14 [INFO] [exec] nxdrive.client.remote_filtered_file_system_client: TRACE: server_binding.last_filter_date = None 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Updating remote states 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Processing local scan to detect local changes 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state='modified', remote_state=u'synchronized', pair_state='locally_modified'> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 1 pending item(s) 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state=u'modified', remote_state=u'synchronized', pair_state=u'locally_modified', error_count=0>] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state=u'modified', remote_state=u'synchronized', pair_state=u'locally_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'parentId': u'collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "parentId": "collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"b8ab309a6b9a3f448092a136afa8fa25","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688974755,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_locally_modified of <nxdrive.synchronizer.Synchronizer object at 0x05BCD4D0>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state=u'modified', remote_state=u'synchronized', pair_state=u'locally_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Updating remote document 'test.odt'. 01:23:14 [INFO] [exec] nxdrive.utils: TRACE: Guessed mime type 'application/vnd.oasis.opendocument.text' for 'test.odt' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 36L, 'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'X-File-Type': 'application/vnd.oasis.opendocument.text', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 36L, 'Cache-Control': 'no-cache', 'X-Batch-Id': '1418688976.78_265917369', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'test.odt', 'X-Client-Version': '1.3.1216'} and cookies [] for file c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\Locally Edited\test.odt 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies []: '{"uploaded":"true","batchId":"1418688976.78_265917369"}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Using 300 seconds [max(300, 2 * upload time=0)] as Nuxeo transaction timeout for batch execution of NuxeoDrive.UpdateFile with file c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\Locally Edited\test.odt 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1418688976.78_265917369', 'parentId': u'collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115', 'fileIdx': '0', 'id': u'defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'operationId': 'NuxeoDrive.UpdateFile'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-Application-Name': 'Nuxeo Drive', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'Nuxeo-Transaction-Timeout': 300, 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"batchId": "1418688976.78_265917369", "parentId": "collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115", "fileIdx": "0", "id": "defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "operationId": "NuxeoDrive.UpdateFile"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies []: '{"digest":"c582bff033c8874b660d6f067664834f","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688976799,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'parentId': u'collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "parentId": "collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"c582bff033c8874b660d6f067664834f","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688976799,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Doc test.odt is a file that has been renamed, moved, for which the content has been updated or restored from the trash, set remote_state to 'modified' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state=u'modified', remote_state='modified', pair_state='conflicted'> 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/Locally Edited/test.odt', remote_name=u'test.odt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'> 01:23:14 [INFO] [exec] nxdrive.controller: TRACE: Updated list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [u'test.odt', u'test.odt'] 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: [c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 1, pending: 1, local: 0.031s, remote: 0.016s sync: 0.172s 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 1 loops 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x06D90870>, ending any transaction in progress and releasing underlying connections from the pool 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: As we are under Windows, dispose connection pool to make sure all connections are closed, avoiding any WindowsError due to a Python process using the database file 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping all FS Observers thread 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/syncRoot/test.odt', 'params': {}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Blob.Get with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/syncRoot/test.odt", "params": {}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Blob.Get' with cookies [] has content-type 'application/vnd.oasis.opendocument.text' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type '' 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=1600) 01:23:14 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [u'test.odt', u'test.odt'] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Fetching remote change summary 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lowerBound': 898, 'lastSyncActiveRootDefinitions': u'default:8c8b872e-a51d-4073-b134-0b9bd3d9b115,default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"lowerBound": 898, "lastSyncActiveRootDefinitions": "default:8c8b872e-a51d-4073-b134-0b9bd3d9b115,default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"activeSynchronizationRootDefinitions":"default:8c8b872e-a51d-4073-b134-0b9bd3d9b115,default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c","syncDate":1418688976000,"upperBound":906,"fileSystemChanges":[{"eventId":"documentModified","fileSystemItemName":"test.odt","eventDate":1418688976799,"docUuid":"86d321c0-cdeb-4e6e-bfd6-6113dd50f433","repositoryId":"default","fileSystemItem":{"digest":"c582bff033c8874b660d6f067664834f","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688976799,"userName":"nuxeoDriveTestUser_user_1"},"fileSystemItemId":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433"}],"hasTooManyChanges":false}' 01:23:14 [INFO] [exec] nxdrive.client.remote_filtered_file_system_client: TRACE: result['hasTooManyChanges'] = False 01:23:14 [INFO] [exec] nxdrive.client.remote_filtered_file_system_client: TRACE: server_binding.last_filter_date = None 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Updating remote states 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: 1 remote changes detected on http://localhost:8080/nuxeo/ 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Refreshing remote state info for doc_pair '/syncRoot/test.odt' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Doc test.odt is a file that has been renamed, moved, for which the content has been updated or restored from the trash, set remote_state to 'modified' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state=u'synchronized', remote_state='modified', pair_state='remotely_modified'> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Refreshing remote state info for doc_pair '/Locally Edited/test.odt' 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Processing local scan to detect local changes 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 1 pending item(s) 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state=u'synchronized', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0>] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state=u'synchronized', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'parentId': u'defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "parentId": "defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"c582bff033c8874b660d6f067664834f","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688976799,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_remotely_modified of <nxdrive.synchronizer.Synchronizer object at 0x05BCD4D0>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state=u'synchronized', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Updating content of local file 'c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\syncRoot\test.odt'. 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'parentId': u'defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "parentId": "defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"c582bff033c8874b660d6f067664834f","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultSyncRootFolderItemFactory#default#a6a56d11-1323-4b99-97ed-5ae4b2917e9c","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688976799,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt' with headers: {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'} 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Ignore next deleteEvent on c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\syncRoot\test.odt 01:23:14 [INFO] [exec] nxdrive.client.local_client: TRACE: Send c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\syncRoot\test.odt to trash 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state='modified', remote_state=u'modified', pair_state='conflicted'> 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'> 01:23:14 [INFO] [exec] nxdrive.controller: TRACE: Updated list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [u'test.odt', u'test.odt'] 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: [c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 1, pending: 1, local: 0.015s, remote: 0.047s sync: 0.078s 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 1 loops 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x06D90870>, ending any transaction in progress and releasing underlying connections from the pool 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: As we are under Windows, dispose connection pool to make sure all connections are closed, avoiding any WindowsError due to a Python process using the database file 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping all FS Observers thread 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/syncRoot/test.odt', 'params': {'target': u'18b6d043-fec3-42c9-a66b-044a232a63cf'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Move with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo0MjI2YmI='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/syncRoot/test.odt", "params": {"target": "18b6d043-fec3-42c9-a66b-044a232a63cf"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Move' with cookies []: '{"entity-type":"document","repository":"default","uid":"86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/test.odt","type":"File","state":"project","parentRef":"18b6d043-fec3-42c9-a66b-044a232a63cf","versionLabel":"0.0","isCheckedOut":true,"title":"test.odt","lastModified":"2014-12-16T00:16:16.79Z","properties":{"uid:uid":null,"uid:minor_version":0,"uid:major_version":0,"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2014-12-16T00:16:14.69Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-16T00:16:16.79Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"test.odt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"thumb:thumbnail":{"name":"d25f445c77069f3647cc8c442de626a7","mime-type":"application/octet-stream","encoding":null,"digest":"d25f445c77069f3647cc8c442de626a7","length":"778","data":"http://localhost:8080/nuxeo/nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/thumbnail:thumb:thumbnail/d25f445c77069f3647cc8c442de626a7"},"common:icon":"/icons/odt.png","common:icon-expanded":null,"common:size":36,"file:content":{"name":"test.odt","mime-type":"application/vnd.oasis.opendocument.text","encoding":null,"digest":"c582bff033c8874b660d6f067664834f","length":"36","data":"http://localhost:8080/nuxeo/nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/file:content/test.odt"},"file:filename":"test.odt","collectionMember:collectionIds":["8c8b872e-a51d-4073-b134-0b9bd3d9b115"],"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","CollectionMember","Versionable","Publishable","HasRelatedText","Thumbnail"],"changeToken":"1418688976799","contextParameters":{}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion with headers {'X-Client-Version': '1.3.1216', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type '' 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=1600) 01:23:14 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [u'test.odt', u'test.odt'] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Fetching remote change summary 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lowerBound': 906, 'lastSyncActiveRootDefinitions': u'default:8c8b872e-a51d-4073-b134-0b9bd3d9b115,default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"lowerBound": 906, "lastSyncActiveRootDefinitions": "default:8c8b872e-a51d-4073-b134-0b9bd3d9b115,default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"activeSynchronizationRootDefinitions":"default:8c8b872e-a51d-4073-b134-0b9bd3d9b115,default:a6a56d11-1323-4b99-97ed-5ae4b2917e9c","syncDate":1418688977000,"upperBound":916,"fileSystemChanges":[{"eventId":"deleted","fileSystemItemName":"test.odt","eventDate":1418688977111,"docUuid":"86d321c0-cdeb-4e6e-bfd6-6113dd50f433","repositoryId":"default","fileSystemItem":{"digest":"c582bff033c8874b660d6f067664834f","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688976799,"userName":"nuxeoDriveTestUser_user_1"},"fileSystemItemId":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433"},{"eventId":"documentMoved","fileSystemItemName":"test.odt","eventDate":1418688977111,"docUuid":"86d321c0-cdeb-4e6e-bfd6-6113dd50f433","repositoryId":"default","fileSystemItem":{"digest":"c582bff033c8874b660d6f067664834f","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688976799,"userName":"nuxeoDriveTestUser_user_1"},"fileSystemItemId":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433"}],"hasTooManyChanges":false}' 01:23:14 [INFO] [exec] nxdrive.client.remote_filtered_file_system_client: TRACE: result['hasTooManyChanges'] = False 01:23:14 [INFO] [exec] nxdrive.client.remote_filtered_file_system_client: TRACE: server_binding.last_filter_date = None 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Updating remote states 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: 2 remote changes detected on http://localhost:8080/nuxeo/ 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Refreshing remote state info for doc_pair '/syncRoot/test.odt' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Doc test.odt is a file that has been renamed, moved, for which the content has been updated or restored from the trash, set remote_state to 'modified' 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state=u'synchronized', remote_state='modified', pair_state='remotely_modified'> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Refreshing remote state info for doc_pair '/Locally Edited/test.odt' 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Processing local scan to detect local changes 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 1 pending item(s) 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state=u'synchronized', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0>] 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state=u'synchronized', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433', 'parentId': u'collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115'}} 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'ee141d43-bc34-4509-8732-f0f8dc21f711', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'bef4f14f84b811e494290024e814f531', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3.1216', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3.1216'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433", "parentId": "collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115"}}' 01:23:14 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"c582bff033c8874b660d6f067664834f","canUpdate":true,"downloadURL":"nxbigfile/default/86d321c0-cdeb-4e6e-bfd6-6113dd50f433/blobholder:0/test.odt","digestAlgorithm":"md5","name":"test.odt","id":"defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115/defaultFileSystemItemFactory#default#86d321c0-cdeb-4e6e-bfd6-6113dd50f433","creationDate":1418688974693,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"collectionSyncRootFolderItemFactory#default#8c8b872e-a51d-4073-b134-0b9bd3d9b115","canRename":true,"canDelete":true,"lastContributor":"nuxeoDriveTestUser_user_1","lastModificationDate":1418688976799,"userName":"nuxeoDriveTestUser_user_1"}' 01:23:14 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_remotely_modified of <nxdrive.synchronizer.Synchronizer object at 0x05BCD4D0>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/syncRoot/test.odt', remote_name=u'test.odt', local_state=u'synchronized', remote_state=u'modified', pair_state=u'remotely_modified', error_count=0> 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Moving local file 'c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\syncRoot\test.odt' to 'c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive\Locally Edited'. 01:23:14 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'c:\\users\\nuxeo\\appdata\\local\\temp\\tmp1jedc0-nxdrive-tests-user-1\\Nuxeo Drive', local_path=u'/Locally Edited/test__1.odt', remote_name=u'test.odt', local_state=u'synchronized', remote_state='synchronized', pair_state='synchronized'> 01:23:14 [INFO] [exec] nxdrive.controller: TRACE: Updated list of recently modified items in c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive: [u'test__1.odt', u'test.odt'] 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: [c:\users\nuxeo\appdata\local\temp\tmp1jedc0-nxdrive-tests-user-1\Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 1, pending: 1, local: 0.015s, remote: 0.094s sync: 0.063s 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 1 loops 01:23:14 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x06D90870>, ending any transaction in progress and releasing underlying connections from the pool 01:23:14 [INFO] [exec] nxdrive.controller: DEBUG: As we are under Windows, dispose connection pool to make sure all connections are closed, avoiding any WindowsError due to a Python process using the database file 01:23:14 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping all FS Observers thread 01:23:14 [INFO] [exec] --------------------- >> end captured logging << ---------------------
- is required by
-
NXDRIVE-184 Random failure at line 231, in test_drive_edit_remote_move_non_sync_root_to_sync_root
-
- Resolved
-
-
NXDRIVE-170 Refactor functional test framework to run the ndrive program instead of relying on its implementation
-
- Resolved
-
