See http://qa.nuxeo.org/jenkins/view/Drive/job/FT-nuxeo-drive-master-osx/376/:
07:28:12 [INFO] [exec] ======================================================================
07:28:12 [INFO] [exec] ERROR: test_synchronize_paged_delete_detection (nxdrive.tests.test_integration_synchronization.TestIntegrationSynchronization)
07:28:12 [INFO] [exec] ----------------------------------------------------------------------
07:28:12 [INFO] [exec] Traceback (most recent call last):
07:28:12 [INFO] [exec] File "/Users/hudson/tmp/workspace/FT-nuxeo-drive-master-osx/nuxeo-drive-client/nxdrive/tests/test_integration_synchronization.py", line 1200, in test_synchronize_paged_delete_detection
07:28:12 [INFO] [exec] syn.loop(delay=0.1, max_loops=1)
07:28:12 [INFO] [exec] File "/Users/hudson/tmp/workspace/FT-nuxeo-drive-master-osx/nuxeo-drive-client/nxdrive/synchronizer.py", line 1600, in loop
07:28:12 [INFO] [exec] observer.stop()
07:28:12 [INFO] [exec] File "/usr/local/lib/python2.7/site-packages/watchdog/utils/__init__.py", line 113, in stop
07:28:12 [INFO] [exec] self.on_thread_stop()
07:28:12 [INFO] [exec] File "/usr/local/lib/python2.7/site-packages/watchdog/observers/api.py", line 396, in on_thread_stop
07:28:12 [INFO] [exec] self.unschedule_all()
07:28:12 [INFO] [exec] File "/usr/local/lib/python2.7/site-packages/watchdog/observers/api.py", line 392, in unschedule_all
07:28:12 [INFO] [exec] self._clear_emitters()
07:28:12 [INFO] [exec] File "/usr/local/lib/python2.7/site-packages/watchdog/observers/api.py", line 268, in _clear_emitters
07:28:12 [INFO] [exec] for emitter in self._emitters:
07:28:12 [INFO] [exec] TypeError: PyCObject_AsVoidPtr called with null pointer
07:28:12 [INFO] [exec] -------------------- >> begin captured logging << --------------------
07:28:12 [INFO] [exec] nxdrive.controller: INFO: nxdrive installed in '/Users/hudson/tmp/workspace/FT-nuxeo-drive-master-osx/nuxeo-drive-client/nxdrive'
07:28:12 [INFO] [exec] nxdrive.controller: INFO: nxdrive configured in '/private/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/nuxeo-drive-conf'
07:28:12 [INFO] [exec] alembic.migration: INFO: Context impl SQLiteImpl.
07:28:12 [INFO] [exec] alembic.migration: INFO: Will assume non-transactional DDL.
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Checking if SQLite database migration is needed.
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Head Alembic revision: 2f126b5f61a6
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Alembic is not initialized, setting current revision to head revision: 2f126b5f61a6
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Current Alembic revision: 2f126b5f61a6
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: No migration to process as current Alembic revision in SQLite database is already the head revision.
07:28:12 [INFO] [exec] nxdrive.model: DEBUG: Set client version to 1.3-dev
07:28:12 [INFO] [exec] nxdrive.controller: INFO: nxdrive installed in '/Users/hudson/tmp/workspace/FT-nuxeo-drive-master-osx/nuxeo-drive-client/nxdrive'
07:28:12 [INFO] [exec] nxdrive.controller: INFO: nxdrive configured in '/private/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpKJmIgl-nxdrive-tests-user-2/nuxeo-drive-conf'
07:28:12 [INFO] [exec] alembic.migration: INFO: Context impl SQLiteImpl.
07:28:12 [INFO] [exec] alembic.migration: INFO: Will assume non-transactional DDL.
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Checking if SQLite database migration is needed.
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Head Alembic revision: 2f126b5f61a6
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Alembic is not initialized, setting current revision to head revision: 2f126b5f61a6
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Current Alembic revision: 2f126b5f61a6
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: No migration to process as current Alembic revision in SQLite database is already the head revision.
07:28:12 [INFO] [exec] nxdrive.model: DEBUG: Set client version to 1.3-dev
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-administrator-device', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'} and cookies []
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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": "/"}}'
07:28:12 [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":"33f6f1c8-6fc2-46e9-af9e-c926502a67cc","path":"/","type":"Root","state":null,"versionLabel":"","isCheckedOut":true,"title":"33f6f1c8-6fc2-46e9-af9e-c926502a67cc","properties":{"dc:creator":null,"dc:source":null,"dc:contributors":[],"dc:nature":null,"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":{}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'userNames': 'user_1, user_2', 'permission': 'ReadWrite'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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"}}'
07:28:12 [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'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/default-domain/workspaces/nuxeo-drive-test-workspace'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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"}}'
07:28:12 [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":"cb97650f-a43f-4918-b01b-6feb39d98f29","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-09-16T05:26:44.15Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:contributors":["Administrator"],"dc:nature":null,"dc:created":"2014-09-16T05:26:44.15Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-09-16T05:26:44.15Z","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:useCaptcha":null,"webc:welcomeText":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":"1410845204157","contextParameters":{}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='} and cookies []
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'cb97650f-a43f-4918-b01b-6feb39d98f29'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='}, cookies [] and JSON payload '{"params": {"value": "cb97650f-a43f-4918-b01b-6feb39d98f29"}}'
07:28:12 [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":"cb97650f-a43f-4918-b01b-6feb39d98f29","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-09-16T05:26:44.15Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:contributors":["Administrator"],"dc:nature":null,"dc:created":"2014-09-16T05:26:44.15Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-09-16T05:26:44.15Z","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:useCaptcha":null,"webc:welcomeText":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":"1410845204157","contextParameters":{}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-2', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjpkY2VkMjA='} and cookies []
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'cb97650f-a43f-4918-b01b-6feb39d98f29'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-2', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjpkY2VkMjA='}, cookies [] and JSON payload '{"params": {"value": "cb97650f-a43f-4918-b01b-6feb39d98f29"}}'
07:28:12 [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":"cb97650f-a43f-4918-b01b-6feb39d98f29","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-09-16T05:26:44.15Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:contributors":["Administrator"],"dc:nature":null,"dc:created":"2014-09-16T05:26:44.15Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-09-16T05:26:44.15Z","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:useCaptcha":null,"webc:welcomeText":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":"1410845204157","contextParameters":{}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='} and cookies []
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-2', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjpkY2VkMjA='} and cookies []
07:28:12 [INFO] [exec] nxdrive.controller: INFO: nxdrive installed in '/Users/hudson/tmp/workspace/FT-nuxeo-drive-master-osx/nuxeo-drive-client/nxdrive'
07:28:12 [INFO] [exec] nxdrive.controller: INFO: nxdrive configured in '/private/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/nuxeo-drive-conf'
07:28:12 [INFO] [exec] alembic.migration: INFO: Context impl SQLiteImpl.
07:28:12 [INFO] [exec] alembic.migration: INFO: Will assume non-transactional DDL.
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Checking if SQLite database migration is needed.
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Head Alembic revision: 2f126b5f61a6
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: Current Alembic revision: 2f126b5f61a6
07:28:12 [INFO] [exec] nxdrive.migration: DEBUG: No migration to process as current Alembic revision in SQLite database is already the head revision.
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='} and cookies []
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/authentication/token?applicationName=Nuxeo+Drive&deviceDescription=Mac+OSX+Desktop&revoke=false&deviceId=0ba071d13d6211e49d6b002500d3a152&permission=ReadWrite with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='} and cookies []
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Got token '1a1bf900-5b23-4a1e-8c12-99263caf0e81' with cookies []
07:28:12 [INFO] [exec] nxdrive.controller: INFO: Binding '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive' to 'http://localhost:8080/nuxeo/' with account 'nuxeoDriveTestUser_user_1'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3-dev'} and cookies []
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder' with cookies []: '{"canCreateChild":false,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","creationDate":512,"parentId":null,"folder":true,"creator":"system","canDelete":false,"lastModificationDate":512,"canRename":false,"userName":"nuxeoDriveTestUser_user_1"}'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/', remote_name=None, local_state=None, remote_state=None, pair_state='unknown'>
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '1970-01-01 01:00:00'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 1970-01-01 01:00:00 and updated last_sync_date to 2014-09-16 07:26:44.515015
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/', remote_name=u'Nuxeo Drive', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo' with cookies []: '{"serverVersion":"5.9.6-SNAPSHOT","updateSiteURL":"http://community.nuxeo.com/static/drive/"}'
07:28:12 [INFO] [exec] nxdrive.controller: INFO: Fetched update info from server: {u'serverVersion': u'5.9.6-SNAPSHOT', u'updateSiteURL': u'http://community.nuxeo.com/static/drive/'}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3-dev'} and cookies []
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:cb97650f-a43f-4918-b01b-6feb39d98f29', 'params': {'enable': True}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization with headers {'X-Authentication-Token': u'1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"input": "doc:cb97650f-a43f-4918-b01b-6feb39d98f29", "params": {"enable": true}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization' with cookies [] has content-type ''
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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": {}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type ''
07:28:12 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=43553)
07:28:12 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive: []
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Fetching remote change summary
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"upperBound":7121,"fileSystemChanges":[],"syncDate":1410845204000,"activeSynchronizationRootDefinitions":"default:cb97650f-a43f-4918-b01b-6feb39d98f29","hasTooManyChanges":false}'
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote full scan of /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive. Reasons: forced: False, too many changes: False, first pass: True
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#"}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":false,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","creationDate":810,"parentId":null,"folder":true,"creator":"system","canDelete":false,"lastModificationDate":810,"canRename":false,"userName":"nuxeoDriveTestUser_user_1"}'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '1970-01-01 01:00:00', '1970-01-01 01:00:00'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#"}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"canCreateChild":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29","name":"Nuxeo Drive Test Workspace","id":"defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29","creationDate":1410845204157,"parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","folder":true,"creator":"Administrator","canDelete":true,"lastModificationDate":1410845204601,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"}]'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-09-16 07:26:44'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-09-16 07:26:44 and updated last_sync_date to 2014-09-16 07:26:44.842726
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Nuxeo Drive Test Workspace', local_state=None, remote_state=None, pair_state='unknown'>
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Nuxeo Drive Test Workspace', local_state='unknown', remote_state='unknown', pair_state='unknown', error_count=0>
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-09-16 07:26:44', '2014-09-16 07:26:44'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29"}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[]'
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Using Watchdog to detect local changes
07:28:12 [INFO] [exec] nxdrive.synchronizer: INFO: Watching FS modification on : /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 1 pending items
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Nuxeo Drive Test Workspace', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>]
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Nuxeo Drive Test Workspace', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29"}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29","name":"Nuxeo Drive Test Workspace","id":"defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29","creationDate":1410845204157,"parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","folder":true,"creator":"Administrator","canDelete":true,"lastModificationDate":1410845204601,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"}'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-09-16 07:26:44', '2014-09-16 07:26:44'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Nuxeo Drive Test Workspace', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_remotely_created of <nxdrive.synchronizer.Synchronizer object at 0x11931c490>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Nuxeo Drive Test Workspace', local_state=u'unknown', remote_state=u'created', pair_state=u'remotely_created', error_count=0>
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local folder 'Nuxeo Drive Test Workspace' in '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/'
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Nuxeo Drive Test Workspace
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-09-16 07:26:44', '2014-09-16 07:26:44'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29"}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[]'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace', remote_name=u'Nuxeo Drive Test Workspace', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
07:28:12 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive: []
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 1, pending: 1, local: 0.029s, remote: 0.156s sync: 0.093s
07:28:12 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 1 loops
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session
07:28:12 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x11a145ad0>, ending any transaction in progress and releasing underlying connections from the pool
07:28:12 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping all FS Observers thread
07:28:12 [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': 'Remote folder', 'properties': 'dc:title=Remote folder'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/", "params": {"type": "Folder", "name": "Remote folder", "properties": "dc:title=Remote folder"}}'
07:28:12 [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":"44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Remote folder","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Remote folder","lastModified":"2014-09-16T05:26:45.06Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-09-16T05:26:45.06Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-09-16T05:26:45.06Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Remote folder","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1410845205065","contextParameters":{}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Remote folder', 'params': {'type': 'File', 'name': 'Remote file 1.odt', 'properties': 'dc:title=Remote file 1.odt'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Remote folder", "params": {"type": "File", "name": "Remote file 1.odt", "properties": "dc:title=Remote file 1.odt"}}'
07:28:12 [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":"2e3d70e7-da0b-4218-ba61-7657447d1f76","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Remote folder/Remote file 1.odt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"Remote file 1.odt","lastModified":"2014-09-16T05:26:45.12Z","properties":{"uid:uid":null,"uid:minor_version":0,"uid:major_version":0,"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-09-16T05:26:45.12Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-09-16T05:26:45.12Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Remote file 1.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":"1410845205122","contextParameters":{}}'
07:28:12 [INFO] [exec] nxdrive.utils: TRACE: Guessed mime type 'application/vnd.oasis.opendocument.text' for 'Remote file 1.odt'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 1048576 bytes
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 13, 'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'application/vnd.oasis.opendocument.text', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 13, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1410845205.16_306123747', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'Remote%20file%201.odt'} and cookies [] for file /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpk6rzJp-nxdrive-uploads/tmpv6kK7a-nxdrive-file-to-upload
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies []: '{"uploaded":"true","batchId":"1410845205.16_306123747"}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1410845205.16_306123747', 'document': u'2e3d70e7-da0b-4218-ba61-7657447d1f76', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='}, cookies [] and JSON payload '{"params": {"batchId": "1410845205.16_306123747", "document": "2e3d70e7-da0b-4218-ba61-7657447d1f76", "fileIdx": "0", "operationId": "Blob.Attach"}}'
07:28:12 [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'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Remote folder', 'params': {'type': 'File', 'name': 'Remote file 2.odt', 'properties': 'dc:title=Remote file 2.odt'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Remote folder", "params": {"type": "File", "name": "Remote file 2.odt", "properties": "dc:title=Remote file 2.odt"}}'
07:28:12 [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":"f27909f1-fa5e-4f00-a2ab-93f11dd3150c","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Remote folder/Remote file 2.odt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"Remote file 2.odt","lastModified":"2014-09-16T05:26:45.21Z","properties":{"uid:uid":null,"uid:minor_version":0,"uid:major_version":0,"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-09-16T05:26:45.21Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-09-16T05:26:45.21Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Remote file 2.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":"1410845205211","contextParameters":{}}'
07:28:12 [INFO] [exec] nxdrive.utils: TRACE: Guessed mime type 'application/vnd.oasis.opendocument.text' for 'Remote file 2.odt'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 1048576 bytes
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 14, 'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'application/vnd.oasis.opendocument.text', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 14, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1410845205.26_821039603', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'Remote%20file%202.odt'} and cookies [] for file /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpk6rzJp-nxdrive-uploads/tmppHddep-nxdrive-file-to-upload
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies []: '{"uploaded":"true","batchId":"1410845205.26_821039603"}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1410845205.26_821039603', 'document': u'f27909f1-fa5e-4f00-a2ab-93f11dd3150c', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='}, cookies [] and JSON payload '{"params": {"batchId": "1410845205.26_821039603", "document": "f27909f1-fa5e-4f00-a2ab-93f11dd3150c", "fileIdx": "0", "operationId": "Blob.Attach"}}'
07:28:12 [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'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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": {}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type ''
07:28:12 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=43553)
07:28:12 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive: []
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Fetching remote change summary
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lowerBound': 7121, 'lastSyncActiveRootDefinitions': u'default:cb97650f-a43f-4918-b01b-6feb39d98f29'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"lowerBound": 7121, "lastSyncActiveRootDefinitions": "default:cb97650f-a43f-4918-b01b-6feb39d98f29"}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"upperBound":7139,"fileSystemChanges":[{"eventId":"documentModified","eventDate":1410845205300,"fileSystemItem":{"digest":"39181c49e54b6e5ae8be13ab66f9fdb8","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/f27909f1-fa5e-4f00-a2ab-93f11dd3150c/blobholder:0/Remote%20file%202.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","name":"Remote file 2.odt","id":"defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","creationDate":1410845205211,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205281,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"},"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","fileSystemItemName":"Remote file 2.odt","docUuid":"f27909f1-fa5e-4f00-a2ab-93f11dd3150c"},{"eventId":"documentCreated","eventDate":1410845205211,"fileSystemItem":{"digest":"39181c49e54b6e5ae8be13ab66f9fdb8","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/f27909f1-fa5e-4f00-a2ab-93f11dd3150c/blobholder:0/Remote%20file%202.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","name":"Remote file 2.odt","id":"defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","creationDate":1410845205211,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205281,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"},"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","fileSystemItemName":"Remote file 2.odt","docUuid":"f27909f1-fa5e-4f00-a2ab-93f11dd3150c"},{"eventId":"documentModified","eventDate":1410845205186,"fileSystemItem":{"digest":"b8ab309a6b9a3f448092a136afa8fa25","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/2e3d70e7-da0b-4218-ba61-7657447d1f76/blobholder:0/Remote%20file%201.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","name":"Remote file 1.odt","id":"defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","creationDate":1410845205122,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205181,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"},"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","fileSystemItemName":"Remote file 1.odt","docUuid":"2e3d70e7-da0b-4218-ba61-7657447d1f76"},{"eventId":"documentCreated","eventDate":1410845205122,"fileSystemItem":{"digest":"b8ab309a6b9a3f448092a136afa8fa25","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/2e3d70e7-da0b-4218-ba61-7657447d1f76/blobholder:0/Remote%20file%201.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","name":"Remote file 1.odt","id":"defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","creationDate":1410845205122,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205181,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"},"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","fileSystemItemName":"Remote file 1.odt","docUuid":"2e3d70e7-da0b-4218-ba61-7657447d1f76"},{"eventId":"documentCreated","eventDate":1410845205065,"fileSystemItem":{"canCreateChild":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","name":"Remote folder","id":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","creationDate":1410845205065,"parentId":"defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29","folder":true,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205065,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"},"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","fileSystemItemName":"Remote folder","docUuid":"44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b"}],"syncDate":1410845205000,"activeSynchronizationRootDefinitions":"default:cb97650f-a43f-4918-b01b-6feb39d98f29","hasTooManyChanges":false}'
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Updating remote states
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: 5 remote changes detected on http://localhost:8080/nuxeo/
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Could not match changed document to a bound local folder: RemoteFileInfo(name=u'Remote file 2.odt', uid=u'defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c', parent_uid=u'defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b', path=u'/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c', folderish=False, last_modification_time=datetime.datetime(2014, 9, 16, 7, 26, 45), digest=u'39181c49e54b6e5ae8be13ab66f9fdb8', digest_algorithm=u'md5', download_url=u'nxbigfile/default/f27909f1-fa5e-4f00-a2ab-93f11dd3150c/blobholder:0/Remote%20file%202.odt', can_rename=True, can_delete=True, can_update=True, can_create_child=False)
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Could not match changed document to a bound local folder: RemoteFileInfo(name=u'Remote file 2.odt', uid=u'defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c', parent_uid=u'defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b', path=u'/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c', folderish=False, last_modification_time=datetime.datetime(2014, 9, 16, 7, 26, 45), digest=u'39181c49e54b6e5ae8be13ab66f9fdb8', digest_algorithm=u'md5', download_url=u'nxbigfile/default/f27909f1-fa5e-4f00-a2ab-93f11dd3150c/blobholder:0/Remote%20file%202.odt', can_rename=True, can_delete=True, can_update=True, can_create_child=False)
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Could not match changed document to a bound local folder: RemoteFileInfo(name=u'Remote file 1.odt', uid=u'defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76', parent_uid=u'defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b', path=u'/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76', folderish=False, last_modification_time=datetime.datetime(2014, 9, 16, 7, 26, 45), digest=u'b8ab309a6b9a3f448092a136afa8fa25', digest_algorithm=u'md5', download_url=u'nxbigfile/default/2e3d70e7-da0b-4218-ba61-7657447d1f76/blobholder:0/Remote%20file%201.odt', can_rename=True, can_delete=True, can_update=True, can_create_child=False)
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Could not match changed document to a bound local folder: RemoteFileInfo(name=u'Remote file 1.odt', uid=u'defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76', parent_uid=u'defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b', path=u'/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76', folderish=False, last_modification_time=datetime.datetime(2014, 9, 16, 7, 26, 45), digest=u'b8ab309a6b9a3f448092a136afa8fa25', digest_algorithm=u'md5', download_url=u'nxbigfile/default/2e3d70e7-da0b-4218-ba61-7657447d1f76/blobholder:0/Remote%20file%201.odt', can_rename=True, can_delete=True, can_update=True, can_create_child=False)
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-09-16 07:26:45'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-09-16 07:26:45 and updated last_sync_date to 2014-09-16 07:26:45.483946
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Remote folder', local_state=None, remote_state=None, pair_state='unknown'>
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote folder', local_state='unknown', remote_state='unknown', pair_state='unknown', error_count=0>
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Marked doc_pair 'Remote folder' as remote creation
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Remote folder
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-09-16 07:26:45', '2014-09-16 07:26:45'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b"}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"digest":"b8ab309a6b9a3f448092a136afa8fa25","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/2e3d70e7-da0b-4218-ba61-7657447d1f76/blobholder:0/Remote%20file%201.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","name":"Remote file 1.odt","id":"defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","creationDate":1410845205122,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205181,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"},{"digest":"39181c49e54b6e5ae8be13ab66f9fdb8","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/f27909f1-fa5e-4f00-a2ab-93f11dd3150c/blobholder:0/Remote%20file%202.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","name":"Remote file 2.odt","id":"defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","creationDate":1410845205211,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205281,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"}]'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-09-16 07:26:45'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-09-16 07:26:45 and updated last_sync_date to 2014-09-16 07:26:45.525290
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Remote file 1.odt', local_state=None, remote_state=None, pair_state='unknown'>
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 1.odt', local_state='unknown', remote_state='unknown', pair_state='unknown', error_count=0>
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-09-16 07:26:45', '2014-09-16 07:26:45'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-09-16 07:26:45'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-09-16 07:26:45 and updated last_sync_date to 2014-09-16 07:26:45.536440
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Remote file 2.odt', local_state=None, remote_state=None, pair_state='unknown'>
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 2.odt', local_state='unknown', remote_state='unknown', pair_state='unknown', error_count=0>
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-09-16 07:26:45', '2014-09-16 07:26:45'
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Using Watchdog to detect local changes
07:28:12 [INFO] [exec] nxdrive.synchronizer: INFO: Watching FS modification on : /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 3 pending items
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote folder', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>, LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 1.odt', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>, LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 2.odt', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>]
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote folder', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b"}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","name":"Remote folder","id":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","creationDate":1410845205065,"parentId":"defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29","folder":true,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205065,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"}'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-09-16 07:26:45', '2014-09-16 07:26:45'
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Remote folder', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
07:28:12 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_remotely_created of <nxdrive.synchronizer.Synchronizer object at 0x11931c490>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote folder', local_state=u'unknown', remote_state=u'created', pair_state=u'remotely_created', error_count=0>
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local folder 'Remote folder' in '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'
07:28:12 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Remote folder
07:28:12 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-09-16 07:26:45', '2014-09-16 07:26:45'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b'}}
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b"}}'
07:28:12 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"digest":"b8ab309a6b9a3f448092a136afa8fa25","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/2e3d70e7-da0b-4218-ba61-7657447d1f76/blobholder:0/Remote%20file%201.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","name":"Remote file 1.odt","id":"defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","creationDate":1410845205122,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205181,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"},{"digest":"39181c49e54b6e5ae8be13ab66f9fdb8","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/f27909f1-fa5e-4f00-a2ab-93f11dd3150c/blobholder:0/Remote%20file%202.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","name":"Remote file 2.odt","id":"defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","creationDate":1410845205211,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205281,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"}]'
07:28:13 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder', remote_name=u'Remote folder', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
07:28:13 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive: []
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 2 pending items
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 1.odt', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>, LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 2.odt', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>]
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 1.odt', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76'}}
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76"}}'
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: 1 <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: 2 <DirCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder'>
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"b8ab309a6b9a3f448092a136afa8fa25","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/2e3d70e7-da0b-4218-ba61-7657447d1f76/blobholder:0/Remote%20file%201.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","name":"Remote file 1.odt","id":"defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","creationDate":1410845205122,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205181,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"}'
07:28:13 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-09-16 07:26:45', '2014-09-16 07:26:45'
07:28:13 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Remote file 1.odt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_remotely_created of <nxdrive.synchronizer.Synchronizer object at 0x11931c490>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 1.odt', local_state=u'unknown', remote_state=u'created', pair_state=u'remotely_created', error_count=0>
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local file 'Remote file 1.odt' in '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder'
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76'}}
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76"}}'
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"b8ab309a6b9a3f448092a136afa8fa25","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/2e3d70e7-da0b-4218-ba61-7657447d1f76/blobholder:0/Remote%20file%201.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","name":"Remote file 1.odt","id":"defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","creationDate":1410845205122,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205181,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"}'
07:28:13 [INFO] [exec] nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/2e3d70e7-da0b-4218-ba61-7657447d1f76/blobholder:0/Remote%20file%201.odt' with headers: {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3-dev'}
07:28:13 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder/Remote file 1.odt', remote_name=u'Remote file 1.odt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
07:28:13 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive: [u'Remote file 1.odt']
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 1 pending items
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 2.odt', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>]
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 2.odt', local_state=u'unknown', remote_state=u'unknown', pair_state=u'unknown', error_count=0>
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c'}}
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c"}}'
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: 3 <FileCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder/Remote file 1.odt'>
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"39181c49e54b6e5ae8be13ab66f9fdb8","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/f27909f1-fa5e-4f00-a2ab-93f11dd3150c/blobholder:0/Remote%20file%202.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","name":"Remote file 2.odt","id":"defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","creationDate":1410845205211,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205281,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"}'
07:28:13 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-09-16 07:26:45', '2014-09-16 07:26:45'
07:28:13 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Remote file 2.odt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_remotely_created of <nxdrive.synchronizer.Synchronizer object at 0x11931c490>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Remote file 2.odt', local_state=u'unknown', remote_state=u'created', pair_state=u'remotely_created', error_count=0>
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local file 'Remote file 2.odt' in '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder'
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c'}}
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c"}}'
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"39181c49e54b6e5ae8be13ab66f9fdb8","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/f27909f1-fa5e-4f00-a2ab-93f11dd3150c/blobholder:0/Remote%20file%202.odt","canUpdate":true,"path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#cb97650f-a43f-4918-b01b-6feb39d98f29/defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b/defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","name":"Remote file 2.odt","id":"defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","creationDate":1410845205211,"parentId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","folder":false,"creator":"nuxeoDriveTestUser_user_1","canDelete":true,"lastModificationDate":1410845205281,"canRename":true,"userName":"nuxeoDriveTestUser_user_1"}'
07:28:13 [INFO] [exec] nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/f27909f1-fa5e-4f00-a2ab-93f11dd3150c/blobholder:0/Remote%20file%202.odt' with headers: {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.3-dev'}
07:28:13 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder/Remote file 2.odt', remote_name=u'Remote file 2.odt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
07:28:13 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive: [u'Remote file 2.odt', u'Remote file 1.odt']
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 3, pending: 3, local: 0.036s, remote: 0.147s sync: 0.303s
07:28:13 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 1 loops
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session
07:28:13 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x11a145ad0>, ending any transaction in progress and releasing underlying connections from the pool
07:28:13 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping all FS Observers thread
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Remote folder', 'params': {'value': 'delete'}}
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetLifeCycle with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplMDVlZGE='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Remote folder", "params": {"value": "delete"}}'
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.SetLifeCycle' with cookies []: '{"entity-type":"document","repository":"default","uid":"44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Remote folder","type":"Folder","state":"deleted","versionLabel":"","isCheckedOut":true,"title":"Remote folder","lastModified":"2014-09-16T05:26:45.94Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-09-16T05:26:45.06Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-09-16T05:26:45.94Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Remote folder","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1410845205948","contextParameters":{}}'
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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": {}}'
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type ''
07:28:13 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=43553)
07:28:13 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive: [u'Remote file 2.odt', u'Remote file 1.odt']
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Fetching remote change summary
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lowerBound': 7139, 'lastSyncActiveRootDefinitions': u'default:cb97650f-a43f-4918-b01b-6feb39d98f29'}}
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': '1a1bf900-5b23-4a1e-8c12-99263caf0e81', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'0ba071d13d6211e49d6b002500d3a152', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', '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-dev'}, cookies [] and JSON payload '{"params": {"lowerBound": 7139, "lastSyncActiveRootDefinitions": "default:cb97650f-a43f-4918-b01b-6feb39d98f29"}}'
07:28:13 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"upperBound":7164,"fileSystemChanges":[{"eventId":"deleted","eventDate":1410845205985,"fileSystemItem":null,"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#f27909f1-fa5e-4f00-a2ab-93f11dd3150c","fileSystemItemName":"Remote file 2.odt","docUuid":"f27909f1-fa5e-4f00-a2ab-93f11dd3150c"},{"eventId":"deleted","eventDate":1410845205974,"fileSystemItem":null,"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#2e3d70e7-da0b-4218-ba61-7657447d1f76","fileSystemItemName":"Remote file 1.odt","docUuid":"2e3d70e7-da0b-4218-ba61-7657447d1f76"},{"eventId":"deleted","eventDate":1410845205949,"fileSystemItem":null,"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b","fileSystemItemName":"Remote folder","docUuid":"44ed0bcc-94e6-4ad9-aeec-2b1f2f87f45b"}],"syncDate":1410845206000,"activeSynchronizationRootDefinitions":"default:cb97650f-a43f-4918-b01b-6feb39d98f29","hasTooManyChanges":false}'
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Updating remote states
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: 3 remote changes detected on http://localhost:8080/nuxeo/
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Marking doc_pair 'Remote file 2.odt' as deleted
07:28:13 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder/Remote file 2.odt', remote_name=u'Remote file 2.odt', local_state=u'synchronized', remote_state='deleted', pair_state='remotely_deleted'>
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Marking doc_pair 'Remote file 1.odt' as deleted
07:28:13 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder/Remote file 1.odt', remote_name=u'Remote file 1.odt', local_state=u'synchronized', remote_state='deleted', pair_state='remotely_deleted'>
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Marking doc_pair 'Remote folder' as deleted
07:28:13 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder', remote_name=u'Remote folder', local_state=u'synchronized', remote_state='deleted', pair_state='remotely_deleted'>
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Using Watchdog to detect local changes
07:28:13 [INFO] [exec] nxdrive.synchronizer: INFO: Watching FS modification on : /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Found 3 pending items
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Pending items: [LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder', remote_name=u'Remote folder', local_state=u'synchronized', remote_state=u'deleted', pair_state=u'remotely_deleted', error_count=0>, LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder/Remote file 1.odt', remote_name=u'Remote file 1.odt', local_state=u'synchronized', remote_state=u'deleted', pair_state=u'remotely_deleted', error_count=0>, LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder/Remote file 2.odt', remote_name=u'Remote file 2.odt', local_state=u'synchronized', remote_state=u'deleted', pair_state=u'remotely_deleted', error_count=0>]
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Synchronizing doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder', remote_name=u'Remote folder', local_state=u'synchronized', remote_state=u'deleted', pair_state=u'remotely_deleted', error_count=0>
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Calling <bound method Synchronizer._synchronize_remotely_deleted of <nxdrive.synchronizer.Synchronizer object at 0x11931c490>> on doc pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Remote folder', remote_name=u'Remote folder', local_state=u'synchronized', remote_state=u'deleted', pair_state=u'remotely_deleted', error_count=0>
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Handling Remote file 1.odt for deletion: last_local_updated = 2014-09-16 07:26:45, last_sync_date = 2014-09-16 07:26:45
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Deleting local file '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder/Remote file 1.odt'
07:28:13 [INFO] [exec] nxdrive.client.local_client: INFO: Send /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder/Remote file 1.odt to trash
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: 1 <FileDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder/Remote file 1.odt'>
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: 2 <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder'>
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Handling Remote file 2.odt for deletion: last_local_updated = 2014-09-16 07:26:45, last_sync_date = 2014-09-16 07:26:45
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Deleting local file '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder/Remote file 2.odt'
07:28:13 [INFO] [exec] nxdrive.client.local_client: INFO: Send /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder/Remote file 2.odt to trash
07:28:13 [INFO] [exec] nxdrive.synchronizer: TRACE: Handling Remote folder for deletion: last_local_updated = 2014-09-16 07:26:45, last_sync_date = 2014-09-16 07:26:45
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Deleting local folder '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder'
07:28:13 [INFO] [exec] nxdrive.client.local_client: INFO: Send /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Remote folder to trash
07:28:13 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive: []
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpPksBmb-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 1, pending: 3, local: 0.043s, remote: 0.131s sync: 0.725s
07:28:13 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 1 loops
07:28:13 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session
07:28:13 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x11a145ad0>, ending any transaction in progress and releasing underlying connections from the pool
07:28:13 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping all FS Observers thread
07:28:13 [INFO] [exec] --------------------- >> end captured logging << ---------------------
- depends on
-
NXDRIVE-69 Drive build safety check up
-
- Resolved
-
- is required by
-
-
- Resolved
-
