01:20:59 [INFO] [exec] ======================================================================
01:20:59 [INFO] [exec] FAIL: Test that denying Read access server side is impacted client side
01:20:59 [INFO] [exec] ----------------------------------------------------------------------
01:20:59 [INFO] [exec] Traceback (most recent call last):
01:20:59 [INFO] [exec] File "/Users/hudson/tmp/workspace/FT-nuxeo-drive-master-osx/nuxeo-drive-client/nxdrive/tests/test_integration_security_updates.py", line 77, in test_synchronize_denying_read_access
01:20:59 [INFO] [exec] self.assertTrue(local.exists('/'))
01:20:59 [INFO] [exec] AssertionError: False is not true
01:20:59 [INFO] [exec] -------------------- >> begin captured logging << --------------------
01:20:59 [INFO] [exec] nxdrive.controller: INFO: nxdrive installed in '/Users/hudson/tmp/workspace/FT-nuxeo-drive-master-osx/nuxeo-drive-client/nxdrive'
01:20:59 [INFO] [exec] nxdrive.controller: INFO: nxdrive configured in '/private/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/nuxeo-drive-conf'
01:20:59 [INFO] [exec] alembic.migration: INFO: Context impl SQLiteImpl.
01:20:59 [INFO] [exec] alembic.migration: INFO: Will assume non-transactional DDL.
01:20:59 [INFO] [exec] nxdrive.migration: DEBUG: Checking if SQLite database migration is needed.
01:20:59 [INFO] [exec] nxdrive.migration: DEBUG: Head Alembic revision: 4f23a55ef249
01:20:59 [INFO] [exec] nxdrive.migration: DEBUG: Alembic is not initialized, setting current revision to head revision: 4f23a55ef249
01:20:59 [INFO] [exec] nxdrive.migration: DEBUG: Current Alembic revision: 4f23a55ef249
01:20:59 [INFO] [exec] nxdrive.migration: DEBUG: No migration to process as current Alembic revision in SQLite database is already the head revision.
01:20:59 [INFO] [exec] nxdrive.model: DEBUG: Set client version to 1.3-dev
01:20:59 [INFO] [exec] nxdrive.controller: INFO: nxdrive installed in '/Users/hudson/tmp/workspace/FT-nuxeo-drive-master-osx/nuxeo-drive-client/nxdrive'
01:20:59 [INFO] [exec] nxdrive.controller: INFO: nxdrive configured in '/private/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpMbuwHd-nxdrive-tests-user-2/nuxeo-drive-conf'
01:20:59 [INFO] [exec] alembic.migration: INFO: Context impl SQLiteImpl.
01:20:59 [INFO] [exec] alembic.migration: INFO: Will assume non-transactional DDL.
01:20:59 [INFO] [exec] nxdrive.migration: DEBUG: Checking if SQLite database migration is needed.
01:20:59 [INFO] [exec] nxdrive.migration: DEBUG: Head Alembic revision: 4f23a55ef249
01:20:59 [INFO] [exec] nxdrive.migration: DEBUG: Alembic is not initialized, setting current revision to head revision: 4f23a55ef249
01:20:59 [INFO] [exec] nxdrive.migration: DEBUG: Current Alembic revision: 4f23a55ef249
01:20:59 [INFO] [exec] nxdrive.migration: DEBUG: No migration to process as current Alembic revision in SQLite database is already the head revision.
01:20:59 [INFO] [exec] nxdrive.model: DEBUG: Set client version to 1.3-dev
01:20:59 [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 []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/'}}
01:21:00 [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": "/"}}'
01:21:00 [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":"ab20c54e-4e13-4db4-871b-b36d5f45ca05","path":"/","type":"Root","state":null,"versionLabel":"","isCheckedOut":true,"title":"ab20c54e-4e13-4db4-871b-b36d5f45ca05","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":{}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'userNames': 'user_1, user_2', 'permission': 'ReadWrite'}}
01:21:00 [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"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests' with cookies [] has content-type 'text/plain'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/default-domain/workspaces/nuxeo-drive-test-workspace'}}
01:21:00 [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"}}'
01:21:00 [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":"0c0c60de-4189-4382-b182-af8ec34b883e","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-08-14T23:14:30.14Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:contributors":["Administrator"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.14Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.14Z","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":"1408058070149","contextParameters":{}}'
01:21:00 [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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo5NjVlYzg='} and cookies []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo5NjVlYzg='}, cookies [] and JSON payload '{"params": {"value": "0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [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":"0c0c60de-4189-4382-b182-af8ec34b883e","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-08-14T23:14:30.14Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:contributors":["Administrator"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.14Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.14Z","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":"1408058070149","contextParameters":{}}'
01:21:00 [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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo4OWIxMWI='} and cookies []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo4OWIxMWI='}, cookies [] and JSON payload '{"params": {"value": "0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [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":"0c0c60de-4189-4382-b182-af8ec34b883e","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-08-14T23:14:30.14Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:contributors":["Administrator"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.14Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.14Z","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":"1408058070149","contextParameters":{}}'
01:21:00 [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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo5NjVlYzg='} and cookies []
01:21:00 [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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo4OWIxMWI='} and cookies []
01:21:00 [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'be5598a8240811e4914e002500d3a152', '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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo5NjVlYzg='} and cookies []
01:21:00 [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=be5598a8240811e4914e002500d3a152&permission=ReadWrite with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo5NjVlYzg='} and cookies []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Got token 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a' with cookies []
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Binding '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive' to 'http://localhost:8080/nuxeo/' with account 'nuxeoDriveTestUser_user_1'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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 []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder' with cookies []: '{"canCreateChild":false,"creationDate":578,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","parentId":null,"folder":true,"canDelete":false,"creator":"system","canRename":false,"lastModificationDate":578,"userName":"nuxeoDriveTestUser_user_1"}'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/', remote_name=None, local_state=None, remote_state=None, pair_state='unknown'>
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '1970-01-01 01:00:00'
01:21:00 [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-08-15 01:14:30.590079
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/', remote_name=u'Nuxeo Drive', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {}}'
01:21:00 [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/"}'
01:21:00 [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/'}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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 []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:0c0c60de-4189-4382-b182-af8ec34b883e', 'params': {'enable': True}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization with headers {'X-Authentication-Token': u'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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:0c0c60de-4189-4382-b182-af8ec34b883e", "params": {"enable": true}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization' with cookies [] has content-type ''
01:21:00 [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': 'Test folder', 'properties': 'dc:title=Test folder'}}
01:21:00 [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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo5NjVlYzg='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/", "params": {"type": "Folder", "name": "Test folder", "properties": "dc:title=Test folder"}}'
01:21:00 [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":"50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Test folder","lastModified":"2014-08-14T23:14:30.73Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.73Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.73Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Test folder","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1408058070739","contextParameters":{}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder', 'params': {'type': 'File', 'name': 'joe.txt', 'properties': 'dc:title=joe.txt'}}
01:21:00 [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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo5NjVlYzg='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder", "params": {"type": "File", "name": "joe.txt", "properties": "dc:title=joe.txt"}}'
01:21:00 [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":"1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder/joe.txt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"joe.txt","lastModified":"2014-08-14T23:14:30.84Z","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-08-14T23:14:30.84Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.84Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"joe.txt","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":"1408058070842","contextParameters":{}}'
01:21:00 [INFO] [exec] nxdrive.utils: TRACE: Guessed mime type 'text/plain' for 'joe.txt'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 1048576 bytes
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 12, 'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 12, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo5NjVlYzg=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1408058070.91_589453881', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'joe.txt'} and cookies [] for file /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpsc1z1b-nxdrive-uploads/tmpG4JAYk-nxdrive-file-to-upload
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies []: '{"uploaded":"true","batchId":"1408058070.91_589453881"}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1408058070.91_589453881', 'document': u'1422fd3d-0bb3-4fba-a676-6fde2ec4bf49', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
01:21:00 [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 bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo5NjVlYzg='}, cookies [] and JSON payload '{"params": {"batchId": "1408058070.91_589453881", "document": "1422fd3d-0bb3-4fba-a676-6fde2ec4bf49", "fileIdx": "0", "operationId": "Blob.Attach"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] has content-type 'text/plain'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
01:21:00 [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": {}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type ''
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=43165)
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"fileSystemChanges":[],"syncDate":1408058072000,"activeSynchronizationRootDefinitions":"default:0c0c60de-4189-4382-b182-af8ec34b883e","hasTooManyChanges":false}'
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote full scan of /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive. Reasons: forced: False, too many changes: False, first pass: True
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":false,"creationDate":102,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","parentId":null,"folder":true,"canDelete":false,"creator":"system","canRename":false,"lastModificationDate":102,"userName":"nuxeoDriveTestUser_user_1"}'
01:21:00 [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'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"canCreateChild":true,"creationDate":1408058070149,"name":"Nuxeo Drive Test Workspace","id":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","folder":true,"canDelete":true,"creator":"Administrator","canRename":true,"lastModificationDate":1408058070698,"userName":"nuxeoDriveTestUser_user_1"}]'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-08-15 01:14:30 and updated last_sync_date to 2014-08-15 01:14:32.133908
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-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'>
01:21:00 [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>
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"canCreateChild":true,"creationDate":1408058070739,"name":"Test folder","id":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","parentId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","folder":true,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070739,"userName":"nuxeoDriveTestUser_user_1"}]'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-08-15 01:14:30 and updated last_sync_date to 2014-08-15 01:14:32.168447
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Test folder', local_state=None, remote_state=None, pair_state='unknown'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Test folder', local_state='unknown', remote_state='unknown', pair_state='unknown', error_count=0>
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"digest":"b53227da4280f0e18270f21dd77c91d0","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt","canUpdate":true,"creationDate":1408058070842,"name":"joe.txt","id":"defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609/defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","parentId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","folder":false,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070924,"userName":"nuxeoDriveTestUser_user_1"}]'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-08-15 01:14:30 and updated last_sync_date to 2014-08-15 01:14:32.206359
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'joe.txt', local_state=None, remote_state=None, pair_state='unknown'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'joe.txt', local_state='unknown', remote_state='unknown', pair_state='unknown', error_count=0>
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Watching FS modification on : /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":true,"creationDate":1408058070149,"name":"Nuxeo Drive Test Workspace","id":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","folder":true,"canDelete":true,"creator":"Administrator","canRename":true,"lastModificationDate":1408058070698,"userName":"nuxeoDriveTestUser_user_1"}'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-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'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local folder 'Nuxeo Drive Test Workspace' in '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/'
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Nuxeo Drive Test Workspace
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"canCreateChild":true,"creationDate":1408058070739,"name":"Test folder","id":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","parentId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","folder":true,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070739,"userName":"nuxeoDriveTestUser_user_1"}]'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-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'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 1 <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 2 <DirCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":true,"creationDate":1408058070739,"name":"Test folder","id":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","parentId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","folder":true,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070739,"userName":"nuxeoDriveTestUser_user_1"}'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Test folder', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local folder 'Test folder' in '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Test folder
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"digest":"b53227da4280f0e18270f21dd77c91d0","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt","canUpdate":true,"creationDate":1408058070842,"name":"joe.txt","id":"defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609/defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","parentId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","folder":false,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070924,"userName":"nuxeoDriveTestUser_user_1"}]'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Test folder', remote_name=u'Test folder', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 3 <DirCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"b53227da4280f0e18270f21dd77c91d0","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt","canUpdate":true,"creationDate":1408058070842,"name":"joe.txt","id":"defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609/defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","parentId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","folder":false,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070924,"userName":"nuxeoDriveTestUser_user_1"}'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'joe.txt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local file 'joe.txt' in '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"b53227da4280f0e18270f21dd77c91d0","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt","canUpdate":true,"creationDate":1408058070842,"name":"joe.txt","id":"defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609/defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","parentId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","folder":false,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070924,"userName":"nuxeoDriveTestUser_user_1"}'
01:21:00 [INFO] [exec] nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt' with headers: {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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'}
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Test folder/joe.txt', remote_name=u'joe.txt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: [u'joe.txt']
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 3, pending: 3, local: 0.030s, remote: 0.152s sync: 0.420s
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lastSyncDate': 1408058072000, 'lastSyncActiveRootDefinitions': u'default:0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {"lastSyncDate": 1408058072000, "lastSyncActiveRootDefinitions": "default:0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"fileSystemChanges":[],"syncDate":1408058072000,"activeSynchronizationRootDefinitions":"default:0c0c60de-4189-4382-b182-af8ec34b883e","hasTooManyChanges":false}'
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 4 <FileCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Sorted events: [<DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive'>, <DirCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>, <DirCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>, <FileCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt'>]
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 0, pending: 0, local: 3.029s, remote: 0.014s sync: 0.015s
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 2 loops
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session
01:21:00 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x126442650>, ending any transaction in progress and releasing underlying connections from the pool
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder', 'params': {'permission': 'ReadWrite', 'user': 'nuxeoDriveTestUser_user_1', 'grant': 'false'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE 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 '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder", "params": {"permission": "ReadWrite", "user": "nuxeoDriveTestUser_user_1", "grant": "false"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.SetACE' with cookies []: '{"entity-type":"document","repository":"default","uid":"50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Test folder","lastModified":"2014-08-14T23:14:30.73Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.73Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.73Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Test folder","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1408058070739","contextParameters":{}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder', 'params': {'permission': 'Read', 'user': 'nuxeoDriveTestUser_user_1', 'grant': 'false'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE 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 '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder", "params": {"permission": "Read", "user": "nuxeoDriveTestUser_user_1", "grant": "false"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.SetACE' with cookies []: '{"entity-type":"document","repository":"default","uid":"50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Test folder","lastModified":"2014-08-14T23:14:30.73Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.73Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.73Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Test folder","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1408058070739","contextParameters":{}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
01:21:00 [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": {}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type ''
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=43165)
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: [u'joe.txt']
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lastSyncDate': 1408058072000, 'lastSyncActiveRootDefinitions': u'default:0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {"lastSyncDate": 1408058072000, "lastSyncActiveRootDefinitions": "default:0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"fileSystemChanges":[{"eventId":"securityUpdated","eventDate":1408058075822,"fileSystemItem":null,"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","fileSystemItemName":"Test folder","docUuid":"50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"},{"eventId":"securityUpdated","eventDate":1408058075748,"fileSystemItem":null,"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","fileSystemItemName":"Test folder","docUuid":"50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"}],"syncDate":1408058076000,"activeSynchronizationRootDefinitions":"default:0c0c60de-4189-4382-b182-af8ec34b883e","hasTooManyChanges":false}'
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: 2 remote changes detected on http://localhost:8080/nuxeo/
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Security has been updated for doc_pair 'Test folder' denying Read access, marking it as deleted
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Test folder', remote_name=u'Test folder', local_state=u'synchronized', remote_state='deleted', pair_state='remotely_deleted'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Sorted events: []
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Handling joe.txt for deletion: last_local_updated = 2014-08-15 01:14:32, last_sync_date = 2014-08-15 01:14:32
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Deleting local file '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt'
01:21:00 [INFO] [exec] nxdrive.client.local_client: INFO: Send /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt to trash
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 5 <FileDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 6 <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Handling Test folder for deletion: last_local_updated = 2014-08-15 01:14:32, last_sync_date = 2014-08-15 01:14:32
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Deleting local folder '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'
01:21:00 [INFO] [exec] nxdrive.client.local_client: INFO: Send /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder to trash
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 7 <DirDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 8 <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: []
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 1, pending: 1, local: 3.008s, remote: 0.114s sync: 0.536s
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lastSyncDate': 1408058076000, 'lastSyncActiveRootDefinitions': u'default:0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {"lastSyncDate": 1408058076000, "lastSyncActiveRootDefinitions": "default:0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"fileSystemChanges":[],"syncDate":1408058080000,"activeSynchronizationRootDefinitions":"default:0c0c60de-4189-4382-b182-af8ec34b883e","hasTooManyChanges":false}'
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Sorted events: [<FileDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt'>, <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>, <DirDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>, <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>]
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Unhandle case: <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'> /Nuxeo Drive Test Workspace/Test folder Test folder
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 0, pending: 0, local: 3.027s, remote: 0.017s sync: 0.015s
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 2 loops
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session
01:21:00 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x126442650>, ending any transaction in progress and releasing underlying connections from the pool
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder', 'params': {'permission': 'ReadWrite', 'user': 'nuxeoDriveTestUser_user_1', 'grant': 'true'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE 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 '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder", "params": {"permission": "ReadWrite", "user": "nuxeoDriveTestUser_user_1", "grant": "true"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.SetACE' with cookies []: '{"entity-type":"document","repository":"default","uid":"50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Test folder","lastModified":"2014-08-14T23:14:30.73Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.73Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.73Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Test folder","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1408058070739","contextParameters":{}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder', 'params': {'permission': 'Read', 'user': 'nuxeoDriveTestUser_user_1', 'grant': 'true'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE 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 '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder", "params": {"permission": "Read", "user": "nuxeoDriveTestUser_user_1", "grant": "true"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.SetACE' with cookies []: '{"entity-type":"document","repository":"default","uid":"50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Test folder","lastModified":"2014-08-14T23:14:30.73Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.73Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.73Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Test folder","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1408058070739","contextParameters":{}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
01:21:00 [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": {}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type ''
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=43165)
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lastSyncDate': 1408058080000, 'lastSyncActiveRootDefinitions': u'default:0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {"lastSyncDate": 1408058080000, "lastSyncActiveRootDefinitions": "default:0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"fileSystemChanges":[{"eventId":"securityUpdated","eventDate":1408058083694,"fileSystemItem":{"canCreateChild":true,"creationDate":1408058070739,"name":"Test folder","id":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","parentId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","folder":true,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070739,"userName":"nuxeoDriveTestUser_user_1"},"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","fileSystemItemName":"Test folder","docUuid":"50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"},{"eventId":"securityUpdated","eventDate":1408058083633,"fileSystemItem":{"canCreateChild":true,"creationDate":1408058070739,"name":"Test folder","id":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","parentId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","folder":true,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070739,"userName":"nuxeoDriveTestUser_user_1"},"repositoryId":"default","fileSystemItemId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","fileSystemItemName":"Test folder","docUuid":"50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"}],"syncDate":1408058084000,"activeSynchronizationRootDefinitions":"default:0c0c60de-4189-4382-b182-af8ec34b883e","hasTooManyChanges":false}'
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: 2 remote changes detected on http://localhost:8080/nuxeo/
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-08-15 01:14:30 and updated last_sync_date to 2014-08-15 01:14:44.850362
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Test folder', local_state=None, remote_state=None, pair_state='unknown'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Test folder', local_state='unknown', remote_state='unknown', pair_state='unknown', error_count=0>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Marked doc_pair 'Test folder' as remote creation
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Test folder
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"digest":"b53227da4280f0e18270f21dd77c91d0","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt","canUpdate":true,"creationDate":1408058070842,"name":"joe.txt","id":"defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609/defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","parentId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","folder":false,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070924,"userName":"nuxeoDriveTestUser_user_1"}]'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-08-15 01:14:30 and updated last_sync_date to 2014-08-15 01:14:44.882872
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'joe.txt', local_state=None, remote_state=None, pair_state='unknown'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'joe.txt', local_state='unknown', remote_state='unknown', pair_state='unknown', error_count=0>
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.synchronizer: WARNING: Scan local as unhandled fs event
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":true,"creationDate":1408058070739,"name":"Test folder","id":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","parentId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","folder":true,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070739,"userName":"nuxeoDriveTestUser_user_1"}'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Test folder', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local folder 'Test folder' in '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Test folder
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"digest":"b53227da4280f0e18270f21dd77c91d0","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt","canUpdate":true,"creationDate":1408058070842,"name":"joe.txt","id":"defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609/defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","parentId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","folder":false,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070924,"userName":"nuxeoDriveTestUser_user_1"}]'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Test folder', remote_name=u'Test folder', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 9 <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 10 <DirCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"b53227da4280f0e18270f21dd77c91d0","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt","canUpdate":true,"creationDate":1408058070842,"name":"joe.txt","id":"defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609/defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","parentId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","folder":false,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070924,"userName":"nuxeoDriveTestUser_user_1"}'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'joe.txt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Creating local file 'joe.txt' in '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"digest":"b53227da4280f0e18270f21dd77c91d0","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt","canUpdate":true,"creationDate":1408058070842,"name":"joe.txt","id":"defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609/defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","parentId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","folder":false,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070924,"userName":"nuxeoDriveTestUser_user_1"}'
01:21:00 [INFO] [exec] nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt' with headers: {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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'}
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Test folder/joe.txt', remote_name=u'joe.txt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: [u'joe.txt']
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 2, pending: 2, local: 0.043s, remote: 0.116s sync: 0.191s
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lastSyncDate': 1408058084000, 'lastSyncActiveRootDefinitions': u'default:0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {"lastSyncDate": 1408058084000, "lastSyncActiveRootDefinitions": "default:0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"fileSystemChanges":[],"syncDate":1408058085000,"activeSynchronizationRootDefinitions":"default:0c0c60de-4189-4382-b182-af8ec34b883e","hasTooManyChanges":false}'
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 11 <FileCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 12 <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Sorted events: [<DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>, <DirCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>, <FileCreatedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt'>, <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>]
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 0, pending: 0, local: 3.032s, remote: 0.017s sync: 0.015s
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 2 loops
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session
01:21:00 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x126442650>, ending any transaction in progress and releasing underlying connections from the pool
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace', 'params': {'permission': 'ReadWrite', 'user': 'nuxeoDriveTestUser_user_1', 'grant': 'false'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE 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 '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace", "params": {"permission": "ReadWrite", "user": "nuxeoDriveTestUser_user_1", "grant": "false"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.SetACE' with cookies []: '{"entity-type":"document","repository":"default","uid":"0c0c60de-4189-4382-b182-af8ec34b883e","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-08-14T23:14:30.69Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:contributors":["Administrator","nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.14Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.69Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Nuxeo Drive Test Workspace","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"drv:subscriptions":[{"enabled":true,"username":"nuxeoDriveTestUser_user_1","lastChangeDate":"2014-08-14T23:14:30.69Z"}],"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","DriveSynchronized"],"changeToken":"1408058070698","contextParameters":{}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace', 'params': {'permission': 'Read', 'user': 'nuxeoDriveTestUser_user_1', 'grant': 'false'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE 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 '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace", "params": {"permission": "Read", "user": "nuxeoDriveTestUser_user_1", "grant": "false"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.SetACE' with cookies []: '{"entity-type":"document","repository":"default","uid":"0c0c60de-4189-4382-b182-af8ec34b883e","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-08-14T23:14:30.69Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:contributors":["Administrator","nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.14Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.69Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Nuxeo Drive Test Workspace","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"drv:subscriptions":[{"enabled":true,"username":"nuxeoDriveTestUser_user_1","lastChangeDate":"2014-08-14T23:14:30.69Z"}],"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","DriveSynchronized"],"changeToken":"1408058070698","contextParameters":{}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
01:21:00 [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": {}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type ''
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=43165)
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: [u'joe.txt']
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lastSyncDate': 1408058085000, 'lastSyncActiveRootDefinitions': u'default:0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {"lastSyncDate": 1408058085000, "lastSyncActiveRootDefinitions": "default:0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"fileSystemChanges":[{"eventId":"securityUpdated","eventDate":1408058088249,"fileSystemItem":null,"repositoryId":"default","fileSystemItemId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","fileSystemItemName":"Nuxeo Drive Test Workspace","docUuid":"0c0c60de-4189-4382-b182-af8ec34b883e"},{"eventId":"securityUpdated","eventDate":1408058088207,"fileSystemItem":null,"repositoryId":"default","fileSystemItemId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","fileSystemItemName":"Nuxeo Drive Test Workspace","docUuid":"0c0c60de-4189-4382-b182-af8ec34b883e"}],"syncDate":1408058089000,"activeSynchronizationRootDefinitions":"","hasTooManyChanges":false}'
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: 2 remote changes detected on http://localhost:8080/nuxeo/
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Security has been updated for doc_pair 'Nuxeo Drive Test Workspace' denying Read access, marking it as deleted
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace', remote_name=u'Nuxeo Drive Test Workspace', local_state=u'synchronized', remote_state='deleted', pair_state='remotely_deleted'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Sorted events: []
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Handling joe.txt for deletion: last_local_updated = 2014-08-15 01:14:45, last_sync_date = 2014-08-15 01:14:45
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Deleting local file '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt'
01:21:00 [INFO] [exec] nxdrive.client.local_client: INFO: Send /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt to trash
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 13 <FileDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 14 <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Handling Test folder for deletion: last_local_updated = 2014-08-15 01:14:45, last_sync_date = 2014-08-15 01:14:45
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Deleting local folder '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'
01:21:00 [INFO] [exec] nxdrive.client.local_client: INFO: Send /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder to trash
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Handling Nuxeo Drive Test Workspace for deletion: last_local_updated = 2014-08-15 01:14:44, last_sync_date = 2014-08-15 01:14:44
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Deleting local folder '/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'
01:21:00 [INFO] [exec] nxdrive.client.local_client: INFO: Send /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace to trash
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 15 <DirDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 16 <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 17 <DirDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: 18 <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive'>
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Updated list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: []
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 1, pending: 1, local: 3.008s, remote: 0.111s sync: 0.636s
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lastSyncDate': 1408058089000, 'lastSyncActiveRootDefinitions': u''}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {"lastSyncDate": 1408058089000, "lastSyncActiveRootDefinitions": ""}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"fileSystemChanges":[],"syncDate":1408058093000,"activeSynchronizationRootDefinitions":"","hasTooManyChanges":false}'
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Sorted events: [<FileDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.txt'>, <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>, <DirDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'>, <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>, <DirDeletedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'>, <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive'>]
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Unhandle case: <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'> /Nuxeo Drive Test Workspace/Test folder Test folder
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Unhandle case: <DirModifiedEvent: src_path='/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'> /Nuxeo Drive Test Workspace Nuxeo Drive Test Workspace
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: synchronized: 0, pending: 0, local: 3.112s, remote: 0.099s sync: 0.015s
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 2 loops
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session
01:21:00 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x126442650>, ending any transaction in progress and releasing underlying connections from the pool
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace', 'params': {'permission': 'ReadWrite', 'user': 'nuxeoDriveTestUser_user_1', 'grant': 'true'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE 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 '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace", "params": {"permission": "ReadWrite", "user": "nuxeoDriveTestUser_user_1", "grant": "true"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.SetACE' with cookies []: '{"entity-type":"document","repository":"default","uid":"0c0c60de-4189-4382-b182-af8ec34b883e","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-08-14T23:14:30.69Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:contributors":["Administrator","nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.14Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.69Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Nuxeo Drive Test Workspace","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"drv:subscriptions":[{"enabled":true,"username":"nuxeoDriveTestUser_user_1","lastChangeDate":"2014-08-14T23:14:30.69Z"}],"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","DriveSynchronized"],"changeToken":"1408058070698","contextParameters":{}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace', 'params': {'permission': 'Read', 'user': 'nuxeoDriveTestUser_user_1', 'grant': 'true'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE 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 '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace", "params": {"permission": "Read", "user": "nuxeoDriveTestUser_user_1", "grant": "true"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.SetACE' with cookies []: '{"entity-type":"document","repository":"default","uid":"0c0c60de-4189-4382-b182-af8ec34b883e","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-08-14T23:14:30.69Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:contributors":["Administrator","nuxeoDriveTestUser_user_1"],"dc:nature":null,"dc:created":"2014-08-14T23:14:30.14Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-08-14T23:14:30.69Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Nuxeo Drive Test Workspace","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"drv:subscriptions":[{"enabled":true,"username":"nuxeoDriveTestUser_user_1","lastChangeDate":"2014-08-14T23:14:30.69Z"}],"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","DriveSynchronized"],"changeToken":"1408058070698","contextParameters":{}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
01:21:00 [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": {}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type ''
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Starting synchronization loop (pid=43165)
01:21:00 [INFO] [exec] nxdrive.controller: INFO: Initialized list of recently modified items in /var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive: []
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lastSyncDate': 1408058093000, 'lastSyncActiveRootDefinitions': u''}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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": {"lastSyncDate": 1408058093000, "lastSyncActiveRootDefinitions": ""}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"fileSystemChanges":[{"eventId":"securityUpdated","eventDate":1408058096570,"fileSystemItem":{"canCreateChild":true,"creationDate":1408058070149,"name":"Nuxeo Drive Test Workspace","id":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","folder":true,"canDelete":true,"creator":"Administrator","canRename":true,"lastModificationDate":1408058070698,"userName":"nuxeoDriveTestUser_user_1"},"repositoryId":"default","fileSystemItemId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","fileSystemItemName":"Nuxeo Drive Test Workspace","docUuid":"0c0c60de-4189-4382-b182-af8ec34b883e"},{"eventId":"securityUpdated","eventDate":1408058096522,"fileSystemItem":{"canCreateChild":true,"creationDate":1408058070149,"name":"Nuxeo Drive Test Workspace","id":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","folder":true,"canDelete":true,"creator":"Administrator","canRename":true,"lastModificationDate":1408058070698,"userName":"nuxeoDriveTestUser_user_1"},"repositoryId":"default","fileSystemItemId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","fileSystemItemName":"Nuxeo Drive Test Workspace","docUuid":"0c0c60de-4189-4382-b182-af8ec34b883e"}],"syncDate":1408058097000,"activeSynchronizationRootDefinitions":"default:0c0c60de-4189-4382-b182-af8ec34b883e","hasTooManyChanges":false}'
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: 2 remote changes detected on http://localhost:8080/nuxeo/
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-08-15 01:14:30 and updated last_sync_date to 2014-08-15 01:14:57.723287
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-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'>
01:21:00 [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>
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Marked doc_pair 'Nuxeo Drive Test Workspace' as remote creation
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Nuxeo Drive Test Workspace
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#0c0c60de-4189-4382-b182-af8ec34b883e"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"canCreateChild":true,"creationDate":1408058070739,"name":"Test folder","id":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","parentId":"defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e","folder":true,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070739,"userName":"nuxeoDriveTestUser_user_1"}]'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-08-15 01:14:30 and updated last_sync_date to 2014-08-15 01:14:57.751824
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Test folder', local_state=None, remote_state=None, pair_state='unknown'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Test folder', local_state='unknown', remote_state='unknown', pair_state='unknown', error_count=0>
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609'}}
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': 'f8d53593-f3cc-4ac2-a80c-b3ebb57b335a', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'be5598a8240811e4914e002500d3a152', '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#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609"}}'
01:21:00 [INFO] [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"digest":"b53227da4280f0e18270f21dd77c91d0","digestAlgorithm":"md5","downloadURL":"nxbigfile/default/1422fd3d-0bb3-4fba-a676-6fde2ec4bf49/blobholder:0/joe.txt","canUpdate":true,"creationDate":1408058070842,"name":"joe.txt","id":"defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#0c0c60de-4189-4382-b182-af8ec34b883e/defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609/defaultFileSystemItemFactory#default#1422fd3d-0bb3-4fba-a676-6fde2ec4bf49","parentId":"defaultFileSystemItemFactory#default#50fcd6d9-7ea8-44ac-9fae-2e00fadc7609","folder":false,"canDelete":true,"creator":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1408058070924,"userName":"nuxeoDriveTestUser_user_1"}]'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2014-08-15 01:14:30 and updated last_sync_date to 2014-08-15 01:14:57.784647
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'joe.txt', local_state=None, remote_state=None, pair_state='unknown'>
01:21:00 [INFO] [exec] nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'joe.txt', local_state='unknown', remote_state='unknown', pair_state='unknown', error_count=0>
01:21:00 [INFO] [exec] nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2014-08-15 01:14:30', '2014-08-15 01:14:30'
01:21:00 [INFO] [exec] nxdrive.synchronizer: WARNING: Scan local as unhandled fs event
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: [/var/folders/z2/0qcpf6l97tv6_pz56r7h67gm0000zd/T/tmpmBV6FF-nxdrive-tests-user-1/Nuxeo Drive] - [http://localhost:8080/nuxeo/]: unbinding server because local folder doesn't exist anymore
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Sleeping 0.095s
01:21:00 [INFO] [exec] nxdrive.synchronizer: INFO: Stopping synchronization loop after 2 loops
01:21:00 [INFO] [exec] nxdrive.synchronizer: DEBUG: Calling Controller.dispose() from Synchronizer to close thread-local Session
01:21:00 [INFO] [exec] nxdrive.controller: DEBUG: Closing thread-local Session <sqlalchemy.orm.session.Session object at 0x126442650>, ending any transaction in progress and releasing underlying connections from the pool
01:21:00 [INFO] [exec] --------------------- >> end captured logging << ---------------------
Bug
Minor
NXDRIVE-69 Drive build safety check up
