Uploaded image for project: 'Nuxeo Drive '
  1. Nuxeo Drive
  2. NXDRIVE-228

Fix random readonly test issues

    XMLWordPrintable

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Minor
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 2.0.818
    • Component/s: Tests

      Description

      Occurring at least under Linux and OS X, see Jenkins jobs.

      20:14:33 [INFO]      [exec] ======================================================================
      20:14:33 [INFO]      [exec] FAIL: test_file_readonly_change (nxdrive.tests.test_readonly.TestReadOnly)
      20:14:33 [INFO]      [exec] ----------------------------------------------------------------------
      20:14:33 [INFO]      [exec] Traceback (most recent call last):
      20:14:33 [INFO]      [exec]   File "/opt/hudson/workspace/FT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive/tests/test_readonly.py", line 136, in test_file_readonly_change
      20:14:33 [INFO]      [exec]     self.assertTrue(local.exists('/Test folder/Sub folder 1'))
      20:14:33 [INFO]      [exec] AssertionError: False is not true
      20:14:33 [INFO]      [exec] -------------------- >> begin captured logging << --------------------
      20:14:33 [INFO]      [exec] nxdrive.tests.common_unit_test: DEBUG: Created test home directory: /tmp/tmpOTDjtI-nuxeo-drive-test
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: DEBUG: Create DAO on /tmp/tmpOTDjtI-nuxeo-drive-test/manager.db
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: DEBUG: Create main connexion on /tmp/tmpOTDjtI-nuxeo-drive-test/manager.db(0/1)
      20:14:33 [INFO]      [exec] nxdrive.updater: DEBUG: Application is not frozen, cannot build Esky instance, as a consequence update features won't be available
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.0-dev', 'X-Device-Id': u'nxdrive-test-administrator-device', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-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": "/"}}'
      20:14:33 [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":"c4adc6fe-a5c5-43a5-9e06-6ef8bef8ed54","path":"/","type":"Root","state":null,"parentRef":"/","versionLabel":"","isCheckedOut":true,"title":"c4adc6fe-a5c5-43a5-9e06-6ef8bef8ed54","properties":{"common:size":null,"common:icon-expanded":null,"common:icon":null,"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":null,"dc:modified":null,"dc:lastContributor":null,"dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":null,"dc:title":null,"dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":[],"dc:source":null,"dc:publisher":null},"facets":["Folderish","NotCollectionMember"],"changeToken":null,"contextParameters":{}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'userNames': 'user_1, user_2', 'permission': 'ReadWrite'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-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"}}'
      20:14:33 [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'
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: DEBUG: Create DAO on /tmp/tmpOTDjtI-nuxeo-drive-test/ndrive_0130769abac711e4b931404062563b44.db
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: DEBUG: Create main connexion on /tmp/tmpOTDjtI-nuxeo-drive-test/ndrive_0130769abac711e4b931404062563b44.db(0/1)
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Vacuum sqlite
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Vacuum sqlite finished
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.0-dev', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/authentication/token?applicationName=Nuxeo+Drive&deviceDescription=Linux+Desktop&revoke=false&deviceId=0122c0eabac711e4b931404062563b44&permission=ReadWrite with headers {'X-Client-Version': '2.0-dev', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Got token '4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb' with cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo with headers {'X-Authentication-Token': '4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-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': '2.0-dev'}, cookies [] and JSON payload '{"params": {}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo' with cookies []: '{"updateSiteURL":"http://community.nuxeo.com/static/drive/","serverVersion":"7.2-SNAPSHOT"}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': '4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder with headers {'X-Authentication-Token': '4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder' with cookies []: '{"canCreateChild":false,"creationDate":8,"creator":"system","folder":true,"parentId":null,"lastContributor":"system","canRename":false,"lastModificationDate":8,"canDelete":false,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","userName":"nuxeoDriveTestUser_user_1"}'
      20:14:33 [INFO]      [exec] nxdrive.client.local_client: TRACE: Setting xattr ndriveroot with value http://localhost:8080/nuxeo/|nuxeoDriveTestUser_user_1|0122c0eabac711e4b931404062563b44|0130769abac711e4b931404062563b44 on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: DEBUG: Create DAO on /tmp/tmpOTDjtI-nuxeo-drive-test/ndrive_013fd694bac711e4b931404062563b44.db
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: DEBUG: Create main connexion on /tmp/tmpOTDjtI-nuxeo-drive-test/ndrive_013fd694bac711e4b931404062563b44.db(0/1)
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Vacuum sqlite
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Vacuum sqlite finished
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.0-dev', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjowNmFhN2Q='} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/authentication/token?applicationName=Nuxeo+Drive&deviceDescription=Linux+Desktop&revoke=false&deviceId=0122c0eabac711e4b931404062563b44&permission=ReadWrite with headers {'X-Client-Version': '2.0-dev', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjowNmFhN2Q='} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Got token 'a977b3ce-223a-4eae-849d-d56668312abb' with cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo with headers {'X-Authentication-Token': 'a977b3ce-223a-4eae-849d-d56668312abb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '2.0-dev'}, cookies [] and JSON payload '{"params": {}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetClientUpdateInfo' with cookies []: '{"updateSiteURL":"http://community.nuxeo.com/static/drive/","serverVersion":"7.2-SNAPSHOT"}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': 'a977b3ce-223a-4eae-849d-d56668312abb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder with headers {'X-Authentication-Token': 'a977b3ce-223a-4eae-849d-d56668312abb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder' with cookies []: '{"canCreateChild":false,"creationDate":164,"creator":"system","folder":true,"parentId":null,"lastContributor":"system","canRename":false,"lastModificationDate":164,"canDelete":false,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","userName":"nuxeoDriveTestUser_user_2"}'
      20:14:33 [INFO]      [exec] nxdrive.client.local_client: TRACE: Setting xattr ndriveroot with value http://localhost:8080/nuxeo/|nuxeoDriveTestUser_user_2|0122c0eabac711e4b931404062563b44|013fd694bac711e4b931404062563b44 on /tmp/tmplu3fOb-nxdrive-tests-user-2/Nuxeo Drive
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/default-domain/workspaces/nuxeo-drive-test-workspace'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-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"}}'
      20:14:33 [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":"fd1c386b-9150-4463-85a0-c6b477ff580f","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"f9385495-6fc6-4bdc-95e8-a9b15bb04432","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2015-02-22T19:14:20.89Z","properties":{"webc:themePerspective":null,"webc:useCaptcha":null,"webc:isWebContainer":null,"webc:template":null,"webc:logo":null,"webc:themePage":"workspace","webc:welcomeMedia":null,"webc:name":null,"webc:email":null,"webc:url":null,"webc:baseline":null,"webc:theme":"sites","webc:moderationType":"aposteriori","webc:welcomeText":null,"file:filename":null,"file:content":null,"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/workspace.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"Administrator","dc:modified":"2015-02-22T19:14:20.89Z","dc:lastContributor":"Administrator","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:20.89Z","dc:title":"Nuxeo Drive Test Workspace","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["Administrator"],"dc:source":null,"dc:publisher":null,"publish:sections":[]},"facets":["Folderish","SuperSpace"],"changeToken":"1424632460899","contextParameters":{}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.0-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'fd1c386b-9150-4463-85a0-c6b477ff580f'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='}, cookies [] and JSON payload '{"params": {"value": "fd1c386b-9150-4463-85a0-c6b477ff580f"}}'
      20:14:33 [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":"fd1c386b-9150-4463-85a0-c6b477ff580f","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"f9385495-6fc6-4bdc-95e8-a9b15bb04432","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2015-02-22T19:14:20.89Z","properties":{"webc:themePerspective":null,"webc:useCaptcha":null,"webc:isWebContainer":null,"webc:template":null,"webc:logo":null,"webc:themePage":"workspace","webc:welcomeMedia":null,"webc:name":null,"webc:email":null,"webc:url":null,"webc:baseline":null,"webc:theme":"sites","webc:moderationType":"aposteriori","webc:welcomeText":null,"file:filename":null,"file:content":null,"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/workspace.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"Administrator","dc:modified":"2015-02-22T19:14:20.89Z","dc:lastContributor":"Administrator","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:20.89Z","dc:title":"Nuxeo Drive Test Workspace","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["Administrator"],"dc:source":null,"dc:publisher":null,"publish:sections":[]},"facets":["Folderish","SuperSpace"],"changeToken":"1424632460899","contextParameters":{}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.0-dev', 'X-Device-Id': u'nxdrive-test-device-2', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjowNmFhN2Q='} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'fd1c386b-9150-4463-85a0-c6b477ff580f'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-2', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjowNmFhN2Q='}, cookies [] and JSON payload '{"params": {"value": "fd1c386b-9150-4463-85a0-c6b477ff580f"}}'
      20:14:33 [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":"fd1c386b-9150-4463-85a0-c6b477ff580f","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"f9385495-6fc6-4bdc-95e8-a9b15bb04432","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2015-02-22T19:14:20.89Z","properties":{"webc:themePerspective":null,"webc:useCaptcha":null,"webc:isWebContainer":null,"webc:template":null,"webc:logo":null,"webc:themePage":"workspace","webc:welcomeMedia":null,"webc:name":null,"webc:email":null,"webc:url":null,"webc:baseline":null,"webc:theme":"sites","webc:moderationType":"aposteriori","webc:welcomeText":null,"file:filename":null,"file:content":null,"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/workspace.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"Administrator","dc:modified":"2015-02-22T19:14:20.89Z","dc:lastContributor":"Administrator","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:20.89Z","dc:title":"Nuxeo Drive Test Workspace","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["Administrator"],"dc:source":null,"dc:publisher":null,"publish:sections":[]},"facets":["Folderish","SuperSpace"],"changeToken":"1424632460899","contextParameters":{}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.0-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '2.0-dev', 'X-Device-Id': u'nxdrive-test-device-2', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjowNmFhN2Q='} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:fd1c386b-9150-4463-85a0-c6b477ff580f', 'params': {'enable': True}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='}, cookies [] and JSON payload '{"input": "doc:fd1c386b-9150-4463-85a0-c6b477ff580f", "params": {"enable": true}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization' with cookies [] has content-type ''
      20:14:33 [INFO]      [exec] nxdrive.client.local_client: TRACE: Setting xattr drive-fs-test with value NXDRIVE_VERIFICATION on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:33 [INFO]      [exec] nxdrive.client.local_client: TRACE: Removing xattr drive-fs-test from /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:33 [INFO]      [exec] nxdrive.engine.engine: DEBUG: Engine start
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-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": {}}'
      20:14:33 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread LocalWatcher(140018966828800) start
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: Watching FS modification on : /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type ''
      20:14:33 [INFO]      [exec] nxdrive.tests.common_unit_test: DEBUG: Wait for sync
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event created on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/.watchdog_setup
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/.watchdog_setup
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: Watchdog setup finished
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: Full scan started
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: Full scan finished in 1ms
      20:14:33 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread RemoteWatcher(140018986235648) start
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Remote full scan
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"id": "org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#"}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"canCreateChild":false,"creationDate":404,"creator":"system","folder":true,"parentId":null,"lastContributor":"system","canRename":false,"lastModificationDate":404,"canDelete":false,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","userName":"nuxeoDriveTestUser_user_1"}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"activeSynchronizationRootDefinitions":"default:fd1c386b-9150-4463-85a0-c6b477ff580f","syncDate":1424632463000,"hasTooManyChanges":false,"upperBound":2642,"fileSystemChanges":[]}'
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Remote scanning: /
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"id": "org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#"}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"canCreateChild":true,"creationDate":1424632460899,"creator":"Administrator","folder":true,"parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","lastContributor":"nuxeoDriveTestUser_user_1","canRename":true,"lastModificationDate":1424632461345,"canDelete":true,"name":"Nuxeo Drive Test Workspace","id":"defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f","userName":"nuxeoDriveTestUser_user_1"}]'
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Pushing QueueItem[2](Folderish:1, State: remotely_created)
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Remote scanning: /Nuxeo Drive Test Workspace
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"id": "defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f"}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[]'
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: remote scan finished in 92ms
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Init processors
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: creating remote folder processor
      20:14:33 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread RemoteFolderProcessor(140018525652736) start
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Acquired processor 140018525652736 for row 2
      20:14:33 [INFO]      [exec] nxdrive.engine.processor: TRACE: Calling <bound method Processor._synchronize_remotely_created of <nxdrive.engine.processor.Processor object at 0x7f58c533a808>> on doc pair StateRow[2](Local:/Nuxeo Drive Test Workspace, Remote:defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f, State: remotely_created)
      20:14:33 [INFO]      [exec] nxdrive.engine.processor: DEBUG: Creating local folder 'Nuxeo Drive Test Workspace' in '/tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive'
      20:14:33 [INFO]      [exec] nxdrive.client.local_client: TRACE: Setting xattr ndrive with value defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: DEBUG: Queuing 0 children of '/Nuxeo Drive Test Workspace'
      20:14:33 [INFO]      [exec] nxdrive.engine.processor: TRACE: Finish <bound method Processor._synchronize_remotely_created of <nxdrive.engine.processor.Processor object at 0x7f58c533a808>> on doc pair StateRow[2](Local:/Nuxeo Drive Test Workspace, Remote:defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f, State: remotely_created)
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Released processor 140018525652736
      20:14:33 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread RemoteFolderProcessor(140018525652736) end
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event deleted on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/.watchdog_setup
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event created on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Pushing QueueItem[2](Folderish:1, State: locally_modified)
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: creating local folder processor
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace
      20:14:33 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread LocalFolderProcessor(140018525652736) start
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'} and cookies []
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Acquired processor 140018525652736 for row 2
      20:14:33 [INFO]      [exec] nxdrive.engine.processor: TRACE: Skip as pair is None or in non-processable state: StateRow[2](Local:/Nuxeo Drive Test Workspace, Remote:defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f, State: synchronized)
      20:14:33 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Released processor 140018525652736
      20:14:33 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread LocalFolderProcessor(140018525652736) end
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Handle remote changes
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lowerBound': 2642, 'lastSyncActiveRootDefinitions': u'default:fd1c386b-9150-4463-85a0-c6b477ff580f'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"lowerBound": 2642, "lastSyncActiveRootDefinitions": "default:fd1c386b-9150-4463-85a0-c6b477ff580f"}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"activeSynchronizationRootDefinitions":"default:fd1c386b-9150-4463-85a0-c6b477ff580f","syncDate":1424632466000,"hasTooManyChanges":false,"upperBound":2646,"fileSystemChanges":[]}'
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: Active: LocalFolder: None, LocalFile: None, RemoteFolder: None, RemoteFile: None, Pool:0
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:33 [INFO]      [exec] nxdrive.engine.engine: DEBUG: Checking sync completed: queue manager is inactive and overall size = 0
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: Active: LocalFolder: None, LocalFile: None, RemoteFolder: None, RemoteFile: None, Pool:0
      20:14:33 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:33 [INFO]      [exec] nxdrive.tests.common_unit_test: DEBUG: Sync completed
      20:14:33 [INFO]      [exec] nxdrive.engine.engine: DEBUG: Engine 0130769abac711e4b931404062563b44 stopping
      20:14:33 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread RemoteWatcher(140018986235648) interrupted
      20:14:33 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: INFO: Stopping FS Observer thread
      20:14:33 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread LocalWatcher(140018966828800) interrupted
      20:14:33 [INFO]      [exec] nxdrive.engine.engine: DEBUG: Engine 0130769abac711e4b931404062563b44 stopped
      20:14:33 [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'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/", "params": {"type": "Folder", "name": "Test folder", "properties": "dc:title=Test folder"}}'
      20:14:33 [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":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder","type":"Folder","state":"project","parentRef":"fd1c386b-9150-4463-85a0-c6b477ff580f","versionLabel":"","isCheckedOut":true,"title":"Test folder","lastModified":"2015-02-22T19:14:29.12Z","properties":{"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/folder.gif","dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"nuxeoDriveTestUser_user_1","dc:modified":"2015-02-22T19:14:29.12Z","dc:lastContributor":"nuxeoDriveTestUser_user_1","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:29.12Z","dc:title":"Test folder","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:source":null,"dc:publisher":null},"facets":["Folderish"],"changeToken":"1424632469125","contextParameters":{}}'
      20:14:33 [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.odt', 'properties': 'dc:title=joe.odt'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder", "params": {"type": "File", "name": "joe.odt", "properties": "dc:title=joe.odt"}}'
      20:14:33 [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":"219197f4-dd5f-47ad-b40e-e4645fc86c42","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder/joe.odt","type":"File","state":"project","parentRef":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","versionLabel":"0.0","isCheckedOut":true,"title":"joe.odt","lastModified":"2015-02-22T19:14:29.14Z","properties":{"uid:uid":null,"uid:major_version":0,"uid:minor_version":0,"file:filename":null,"file:content":null,"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/file.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"nuxeoDriveTestUser_user_1","dc:modified":"2015-02-22T19:14:29.14Z","dc:lastContributor":"nuxeoDriveTestUser_user_1","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:29.14Z","dc:title":"joe.odt","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:source":null,"dc:publisher":null,"relatedtext:relatedtextresources":[]},"facets":["Versionable","Publishable","Commentable","HasRelatedText","Downloadable"],"changeToken":"1424632469148","contextParameters":{}}'
      20:14:33 [INFO]      [exec] nxdrive.utils: TRACE: Guessed mime type 'application/vnd.oasis.opendocument.text' for 'joe.odt'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      20:14:33 [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': '2.0-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'application/vnd.oasis.opendocument.text', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 12, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1424632469.17_740128259', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'joe.odt'} and cookies [] for file /tmp/tmpaLL0GW-nxdrive-uploads/tmp6vq0GZ-nxdrive-file-to-upload
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies []: '{"uploaded":"true","batchId":"1424632469.17_740128259"}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Using 300 seconds [max(300, 2 * upload time=0)] as Nuxeo transaction timeout for batch execution of Blob.Attach with file /tmp/tmpaLL0GW-nxdrive-uploads/tmp6vq0GZ-nxdrive-file-to-upload
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1424632469.17_740128259', 'document': u'219197f4-dd5f-47ad-b40e-e4645fc86c42', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-Application-Name': 'Nuxeo Drive', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'Nuxeo-Transaction-Timeout': 300, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='}, cookies [] and JSON payload '{"params": {"batchId": "1424632469.17_740128259", "document": "219197f4-dd5f-47ad-b40e-e4645fc86c42", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] has content-type 'application/vnd.oasis.opendocument.text'
      20:14:33 [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': 'jack.odt', 'properties': 'dc:title=jack.odt'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder", "params": {"type": "File", "name": "jack.odt", "properties": "dc:title=jack.odt"}}'
      20:14:33 [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":"7d185c40-c030-410a-8a37-fe432b46c6bc","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder/jack.odt","type":"File","state":"project","parentRef":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","versionLabel":"0.0","isCheckedOut":true,"title":"jack.odt","lastModified":"2015-02-22T19:14:29.20Z","properties":{"uid:uid":null,"uid:major_version":0,"uid:minor_version":0,"file:filename":null,"file:content":null,"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/file.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"nuxeoDriveTestUser_user_1","dc:modified":"2015-02-22T19:14:29.20Z","dc:lastContributor":"nuxeoDriveTestUser_user_1","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:29.20Z","dc:title":"jack.odt","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:source":null,"dc:publisher":null,"relatedtext:relatedtextresources":[]},"facets":["Versionable","Publishable","Commentable","HasRelatedText","Downloadable"],"changeToken":"1424632469200","contextParameters":{}}'
      20:14:33 [INFO]      [exec] nxdrive.utils: TRACE: Guessed mime type 'application/vnd.oasis.opendocument.text' for 'jack.odt'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      20:14:33 [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': '2.0-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'application/vnd.oasis.opendocument.text', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 12, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1424632469.22_528807894', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'jack.odt'} and cookies [] for file /tmp/tmpaLL0GW-nxdrive-uploads/tmpkClULl-nxdrive-file-to-upload
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies []: '{"uploaded":"true","batchId":"1424632469.22_528807894"}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Using 300 seconds [max(300, 2 * upload time=0)] as Nuxeo transaction timeout for batch execution of Blob.Attach with file /tmp/tmpaLL0GW-nxdrive-uploads/tmpkClULl-nxdrive-file-to-upload
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1424632469.22_528807894', 'document': u'7d185c40-c030-410a-8a37-fe432b46c6bc', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-Application-Name': 'Nuxeo Drive', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'Nuxeo-Transaction-Timeout': 300, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='}, cookies [] and JSON payload '{"params": {"batchId": "1424632469.22_528807894", "document": "7d185c40-c030-410a-8a37-fe432b46c6bc", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] has content-type 'application/vnd.oasis.opendocument.text'
      20:14:33 [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': 'Folder', 'name': 'Sub folder 1', 'properties': 'dc:title=Sub folder 1'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder", "params": {"type": "Folder", "name": "Sub folder 1", "properties": "dc:title=Sub folder 1"}}'
      20:14:33 [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":"eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder/Sub folder 1","type":"Folder","state":"project","parentRef":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","versionLabel":"","isCheckedOut":true,"title":"Sub folder 1","lastModified":"2015-02-22T19:14:29.26Z","properties":{"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/folder.gif","dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"nuxeoDriveTestUser_user_1","dc:modified":"2015-02-22T19:14:29.26Z","dc:lastContributor":"nuxeoDriveTestUser_user_1","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:29.26Z","dc:title":"Sub folder 1","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:source":null,"dc:publisher":null},"facets":["Folderish"],"changeToken":"1424632469268","contextParameters":{}}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder/Sub folder 1', 'params': {'type': 'File', 'name': 'sub file 1.txt', 'properties': 'dc:title=sub file 1.txt'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder/Sub folder 1", "params": {"type": "File", "name": "sub file 1.txt", "properties": "dc:title=sub file 1.txt"}}'
      20:14:33 [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":"3fedec94-8249-41f9-9922-6c3fb73fce53","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder/Sub folder 1/sub file 1.txt","type":"File","state":"project","parentRef":"eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","versionLabel":"0.0","isCheckedOut":true,"title":"sub file 1.txt","lastModified":"2015-02-22T19:14:29.30Z","properties":{"uid:uid":null,"uid:major_version":0,"uid:minor_version":0,"file:filename":null,"file:content":null,"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/file.gif","files:files":[],"dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"nuxeoDriveTestUser_user_1","dc:modified":"2015-02-22T19:14:29.30Z","dc:lastContributor":"nuxeoDriveTestUser_user_1","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:29.30Z","dc:title":"sub file 1.txt","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:source":null,"dc:publisher":null,"relatedtext:relatedtextresources":[]},"facets":["Versionable","Publishable","Commentable","HasRelatedText","Downloadable"],"changeToken":"1424632469305","contextParameters":{}}'
      20:14:33 [INFO]      [exec] nxdrive.utils: TRACE: Guessed mime type 'text/plain' for 'sub file 1.txt'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 7, 'X-Client-Version': '2.0-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 7, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1424632469.32_226252626', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'sub%20file%201.txt'} and cookies [] for file /tmp/tmpaLL0GW-nxdrive-uploads/tmpzhgAAC-nxdrive-file-to-upload
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies []: '{"uploaded":"true","batchId":"1424632469.32_226252626"}'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Using 300 seconds [max(300, 2 * upload time=0)] as Nuxeo transaction timeout for batch execution of Blob.Attach with file /tmp/tmpaLL0GW-nxdrive-uploads/tmpzhgAAC-nxdrive-file-to-upload
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1424632469.32_226252626', 'document': u'3fedec94-8249-41f9-9922-6c3fb73fce53', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-Application-Name': 'Nuxeo Drive', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'Nuxeo-Transaction-Timeout': 300, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMToyZTY2NTk='}, cookies [] and JSON payload '{"params": {"batchId": "1424632469.32_226252626", "document": "3fedec94-8249-41f9-9922-6c3fb73fce53", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      20:14:33 [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'
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder', 'params': {'user': 'nuxeoDriveTestUser_user_1', 'permission': 'Read'}}
      20:14:33 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-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": {"user": "nuxeoDriveTestUser_user_1", "permission": "Read"}}'
      20:14:34 [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":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder","type":"Folder","state":"project","parentRef":"fd1c386b-9150-4463-85a0-c6b477ff580f","versionLabel":"","isCheckedOut":true,"title":"Test folder","lastModified":"2015-02-22T19:14:29.12Z","properties":{"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/folder.gif","dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"nuxeoDriveTestUser_user_1","dc:modified":"2015-02-22T19:14:29.12Z","dc:lastContributor":"nuxeoDriveTestUser_user_1","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:29.12Z","dc:title":"Test folder","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:source":null,"dc:publisher":null},"facets":["Folderish"],"changeToken":"1424632469125","contextParameters":{}}'
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder', 'params': {'user': 'Administrator', 'overwrite': False, 'permission': 'Everything'}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-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": {"user": "Administrator", "overwrite": false, "permission": "Everything"}}'
      20:14:34 [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":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder","type":"Folder","state":"project","parentRef":"fd1c386b-9150-4463-85a0-c6b477ff580f","versionLabel":"","isCheckedOut":true,"title":"Test folder","lastModified":"2015-02-22T19:14:29.12Z","properties":{"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/folder.gif","dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"nuxeoDriveTestUser_user_1","dc:modified":"2015-02-22T19:14:29.12Z","dc:lastContributor":"nuxeoDriveTestUser_user_1","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:29.12Z","dc:title":"Test folder","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:source":null,"dc:publisher":null},"facets":["Folderish"],"changeToken":"1424632469125","contextParameters":{}}'
      20:14:34 [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': 'Everything', 'user': 'Everyone', 'overwrite': False, 'grant': 'false'}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetACE with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-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": "Everything", "user": "Everyone", "overwrite": false, "grant": "false"}}'
      20:14:34 [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":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Test folder","type":"Folder","state":"project","parentRef":"fd1c386b-9150-4463-85a0-c6b477ff580f","versionLabel":"","isCheckedOut":true,"title":"Test folder","lastModified":"2015-02-22T19:14:29.12Z","properties":{"common:size":null,"common:icon-expanded":null,"common:icon":"/icons/folder.gif","dc:description":null,"dc:language":null,"dc:coverage":null,"dc:valid":null,"dc:creator":"nuxeoDriveTestUser_user_1","dc:modified":"2015-02-22T19:14:29.12Z","dc:lastContributor":"nuxeoDriveTestUser_user_1","dc:format":null,"dc:expired":null,"dc:rights":null,"dc:created":"2015-02-22T19:14:29.12Z","dc:title":"Test folder","dc:issued":null,"dc:nature":null,"dc:subjects":[],"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:source":null,"dc:publisher":null},"facets":["Folderish"],"changeToken":"1424632469125","contextParameters":{}}'
      20:14:34 [INFO]      [exec] nxdrive.client.local_client: TRACE: Setting xattr drive-fs-test with value NXDRIVE_VERIFICATION on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:34 [INFO]      [exec] nxdrive.client.local_client: TRACE: Removing xattr drive-fs-test from /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:34 [INFO]      [exec] nxdrive.engine.engine: DEBUG: Engine start
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion with headers {'X-Client-Version': '2.0-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/2.0-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": {}}'
      20:14:34 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread LocalWatcher(140018966828800) start
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: Watching FS modification on : /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: Watchdog setup finished
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: Full scan started
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: Full scan finished in 1ms
      20:14:34 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread RemoteWatcher(140018551092992) start
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Handle remote changes
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lowerBound': 2646, 'lastSyncActiveRootDefinitions': u'default:fd1c386b-9150-4463-85a0-c6b477ff580f'}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"lowerBound": 2646, "lastSyncActiveRootDefinitions": "default:fd1c386b-9150-4463-85a0-c6b477ff580f"}}'
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"activeSynchronizationRootDefinitions":"default:fd1c386b-9150-4463-85a0-c6b477ff580f","syncDate":1424632469000,"hasTooManyChanges":false,"upperBound":2683,"fileSystemChanges":[{"eventId":"securityUpdated","fileSystemItemId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","fileSystemItemName":"Test folder","docUuid":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","eventDate":1424632469432,"repositoryId":"default","fileSystemItem":{"canCreateChild":false,"creationDate":1424632469125,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469125,"canDelete":false,"name":"Test folder","id":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","userName":"nuxeoDriveTestUser_user_1"}},{"eventId":"securityUpdated","fileSystemItemId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","fileSystemItemName":"Test folder","docUuid":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","eventDate":1424632469392,"repositoryId":"default","fileSystemItem":{"canCreateChild":false,"creationDate":1424632469125,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469125,"canDelete":false,"name":"Test folder","id":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","userName":"nuxeoDriveTestUser_user_1"}},{"eventId":"securityUpdated","fileSystemItemId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","fileSystemItemName":"Test folder","docUuid":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","eventDate":1424632469357,"repositoryId":"default","fileSystemItem":{"canCreateChild":false,"creationDate":1424632469125,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469125,"canDelete":false,"name":"Test folder","id":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","userName":"nuxeoDriveTestUser_user_1"}},{"eventId":"documentModified","fileSystemItemId":"defaultFileSystemItemFactory#default#3fedec94-8249-41f9-9922-6c3fb73fce53","fileSystemItemName":"sub file 1.txt","docUuid":"3fedec94-8249-41f9-9922-6c3fb73fce53","eventDate":1424632469337,"repositoryId":"default","fileSystemItem":{"downloadURL":"nxbigfile/default/3fedec94-8249-41f9-9922-6c3fb73fce53/blobholder:0/sub%20file%201.txt","canUpdate":false,"digestAlgorithm":"md5","digest":"f15c1cae7882448b3fb0404682e17e61","creationDate":1424632469305,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469334,"canDelete":false,"name":"sub file 1.txt","id":"defaultFileSystemItemFactory#default#3fedec94-8249-41f9-9922-6c3fb73fce53","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47/defaultFileSystemItemFactory#default#3fedec94-8249-41f9-9922-6c3fb73fce53","userName":"nuxeoDriveTestUser_user_1"}},{"eventId":"documentCreated","fileSystemItemId":"defaultFileSystemItemFactory#default#3fedec94-8249-41f9-9922-6c3fb73fce53","fileSystemItemName":"sub file 1.txt","docUuid":"3fedec94-8249-41f9-9922-6c3fb73fce53","eventDate":1424632469305,"repositoryId":"default","fileSystemItem":{"downloadURL":"nxbigfile/default/3fedec94-8249-41f9-9922-6c3fb73fce53/blobholder:0/sub%20file%201.txt","canUpdate":false,"digestAlgorithm":"md5","digest":"f15c1cae7882448b3fb0404682e17e61","creationDate":1424632469305,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469334,"canDelete":false,"name":"sub file 1.txt","id":"defaultFileSystemItemFactory#default#3fedec94-8249-41f9-9922-6c3fb73fce53","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47/defaultFileSystemItemFactory#default#3fedec94-8249-41f9-9922-6c3fb73fce53","userName":"nuxeoDriveTestUser_user_1"}},{"eventId":"documentCreated","fileSystemItemId":"defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","fileSystemItemName":"Sub folder 1","docUuid":"eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","eventDate":1424632469268,"repositoryId":"default","fileSystemItem":{"canCreateChild":false,"creationDate":1424632469268,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469268,"canDelete":false,"name":"Sub folder 1","id":"defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","userName":"nuxeoDriveTestUser_user_1"}},{"eventId":"documentModified","fileSystemItemId":"defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","fileSystemItemName":"jack.odt","docUuid":"7d185c40-c030-410a-8a37-fe432b46c6bc","eventDate":1424632469245,"repositoryId":"default","fileSystemItem":{"downloadURL":"nxbigfile/default/7d185c40-c030-410a-8a37-fe432b46c6bc/blobholder:0/jack.odt","canUpdate":false,"digestAlgorithm":"md5","digest":"b53227da4280f0e18270f21dd77c91d0","creationDate":1424632469200,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469241,"canDelete":false,"name":"jack.odt","id":"defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","userName":"nuxeoDriveTestUser_user_1"}},{"eventId":"documentCreated","fileSystemItemId":"defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","fileSystemItemName":"jack.odt","docUuid":"7d185c40-c030-410a-8a37-fe432b46c6bc","eventDate":1424632469200,"repositoryId":"default","fileSystemItem":{"downloadURL":"nxbigfile/default/7d185c40-c030-410a-8a37-fe432b46c6bc/blobholder:0/jack.odt","canUpdate":false,"digestAlgorithm":"md5","digest":"b53227da4280f0e18270f21dd77c91d0","creationDate":1424632469200,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469241,"canDelete":false,"name":"jack.odt","id":"defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","userName":"nuxeoDriveTestUser_user_1"}},{"eventId":"documentModified","fileSystemItemId":"defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42","fileSystemItemName":"joe.odt","docUuid":"219197f4-dd5f-47ad-b40e-e4645fc86c42","eventDate":1424632469183,"repositoryId":"default","fileSystemItem":{"downloadURL":"nxbigfile/default/219197f4-dd5f-47ad-b40e-e4645fc86c42/blobholder:0/joe.odt","canUpdate":false,"digestAlgorithm":"md5","digest":"b53227da4280f0e18270f21dd77c91d0","creationDate":1424632469148,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469181,"canDelete":false,"name":"joe.odt","id":"defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42","userName":"nuxeoDriveTestUser_user_1"}},{"eventId":"documentCreated","fileSystemItemId":"defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42","fileSystemItemName":"joe.odt","docUuid":"219197f4-dd5f-47ad-b40e-e4645fc86c42","eventDate":1424632469148,"repositoryId":"default","fileSystemItem":{"downloadURL":"nxbigfile/default/219197f4-dd5f-47ad-b40e-e4645fc86c42/blobholder:0/joe.odt","canUpdate":false,"digestAlgorithm":"md5","digest":"b53227da4280f0e18270f21dd77c91d0","creationDate":1424632469148,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469181,"canDelete":false,"name":"joe.odt","id":"defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42","userName":"nuxeoDriveTestUser_user_1"}},{"eventId":"documentCreated","fileSystemItemId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","fileSystemItemName":"Test folder","docUuid":"e54ce31a-8f39-4898-bdb7-7a373f5624f5","eventDate":1424632469125,"repositoryId":"default","fileSystemItem":{"canCreateChild":false,"creationDate":1424632469125,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469125,"canDelete":false,"name":"Test folder","id":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","userName":"nuxeoDriveTestUser_user_1"}}]}'
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: 11 remote changes detected
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Pushing QueueItem[3](Folderish:1, State: remotely_created)
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: creating remote folder processor
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Marked doc_pair 'Test folder' as remote creation
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Remote recursive scan of the content of Test folder
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Remote scanning: /Nuxeo Drive Test Workspace/Test folder
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5'}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5"}}'
      20:14:34 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread RemoteFolderProcessor(140018525652736) start
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'} and cookies []
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"downloadURL":"nxbigfile/default/219197f4-dd5f-47ad-b40e-e4645fc86c42/blobholder:0/joe.odt","canUpdate":false,"digestAlgorithm":"md5","digest":"b53227da4280f0e18270f21dd77c91d0","creationDate":1424632469148,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469181,"canDelete":false,"name":"joe.odt","id":"defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42","userName":"nuxeoDriveTestUser_user_1"},{"downloadURL":"nxbigfile/default/7d185c40-c030-410a-8a37-fe432b46c6bc/blobholder:0/jack.odt","canUpdate":false,"digestAlgorithm":"md5","digest":"b53227da4280f0e18270f21dd77c91d0","creationDate":1424632469200,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469241,"canDelete":false,"name":"jack.odt","id":"defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","userName":"nuxeoDriveTestUser_user_1"},{"canCreateChild":false,"creationDate":1424632469268,"creator":"nuxeoDriveTestUser_user_1","folder":true,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469268,"canDelete":false,"name":"Sub folder 1","id":"defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","userName":"nuxeoDriveTestUser_user_1"}]'
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Acquired processor 140018525652736 for row 3
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Calling <bound method Processor._synchronize_remotely_created of <nxdrive.engine.processor.Processor object at 0x7f58c533acc8>> on doc pair StateRow[3](Local:/Nuxeo Drive Test Workspace/Test folder, Remote:defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5, State: remotely_created)
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: DEBUG: Creating local folder 'Test folder' in '/tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'
      20:14:34 [INFO]      [exec] nxdrive.client.local_client: TRACE: Setting xattr ndrive with value defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5 on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: DEBUG: Queuing 2 children of '/Nuxeo Drive Test Workspace/Test folder'
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Pushing QueueItem[4](Folderish:0, State: remotely_created)
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Pushing QueueItem[5](Folderish:0, State: remotely_created)
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: creating remote file processor
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread RemoteFileProcessor(140018517260032) start
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'} and cookies []
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Remote scanning: /Nuxeo Drive Test Workspace/Test folder/Sub folder 1
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47'}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47"}}'
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Finish <bound method Processor._synchronize_remotely_created of <nxdrive.engine.processor.Processor object at 0x7f58c533acc8>> on doc pair StateRow[3](Local:/Nuxeo Drive Test Workspace/Test folder, Remote:defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5, State: remotely_created)
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Released processor 140018525652736
      20:14:34 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread RemoteFolderProcessor(140018525652736) end
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"downloadURL":"nxbigfile/default/3fedec94-8249-41f9-9922-6c3fb73fce53/blobholder:0/sub%20file%201.txt","canUpdate":false,"digestAlgorithm":"md5","digest":"f15c1cae7882448b3fb0404682e17e61","creationDate":1424632469305,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469334,"canDelete":false,"name":"sub file 1.txt","id":"defaultFileSystemItemFactory#default#3fedec94-8249-41f9-9922-6c3fb73fce53","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47/defaultFileSystemItemFactory#default#3fedec94-8249-41f9-9922-6c3fb73fce53","userName":"nuxeoDriveTestUser_user_1"}]'
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Acquired processor 140018517260032 for row 4
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Refreshing remote state info for doc_pair '/Nuxeo Drive Test Workspace/Test folder/Sub folder 1/sub file 1.txt' (force_recursion:0)
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Calling <bound method Processor._synchronize_remotely_created of <nxdrive.engine.processor.Processor object at 0x7f58c52b3348>> on doc pair StateRow[4](Local:/Nuxeo Drive Test Workspace/Test folder/joe.odt, Remote:defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42, State: remotely_created)
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Refreshing remote state info for doc_pair '/Nuxeo Drive Test Workspace/Test folder/Sub folder 1' (force_recursion:0)
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Remote scanning: /Nuxeo Drive Test Workspace/Test folder/Sub folder 1
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47'}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47"}}'
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: DEBUG: Creating local file 'joe.odt' in '/tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42', 'parentId': u'defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5'}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42", "parentId": "defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5"}}'
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"downloadURL":"nxbigfile/default/219197f4-dd5f-47ad-b40e-e4645fc86c42/blobholder:0/joe.odt","canUpdate":false,"digestAlgorithm":"md5","digest":"b53227da4280f0e18270f21dd77c91d0","creationDate":1424632469148,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469181,"canDelete":false,"name":"joe.odt","id":"defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42","userName":"nuxeoDriveTestUser_user_1"}'
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/219197f4-dd5f-47ad-b40e-e4645fc86c42/blobholder:0/joe.odt' with headers: {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies []: '[{"downloadURL":"nxbigfile/default/3fedec94-8249-41f9-9922-6c3fb73fce53/blobholder:0/sub%20file%201.txt","canUpdate":false,"digestAlgorithm":"md5","digest":"f15c1cae7882448b3fb0404682e17e61","creationDate":1424632469305,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469334,"canDelete":false,"name":"sub file 1.txt","id":"defaultFileSystemItemFactory#default#3fedec94-8249-41f9-9922-6c3fb73fce53","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#eb2449a7-c0d6-4a1f-9e66-90cf1147bc47/defaultFileSystemItemFactory#default#3fedec94-8249-41f9-9922-6c3fb73fce53","userName":"nuxeoDriveTestUser_user_1"}]'
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Refreshing remote state info for doc_pair '/Nuxeo Drive Test Workspace/Test folder/jack.odt' (force_recursion:0)
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Transfer speed 0 ko/s
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Refreshing remote state info for doc_pair '/Nuxeo Drive Test Workspace/Test folder/joe.odt' (force_recursion:0)
      20:14:34 [INFO]      [exec] nxdrive.client.local_client: TRACE: Setting xattr ndrive with value defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42 on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.odt
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: Active: LocalFolder: None, LocalFile: None, RemoteFolder: None, RemoteFile: <PyQt4.QtCore.QThread object at 0x7f58c52b33e0>, Pool:0
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.engine: DEBUG: Checking sync completed: queue manager is active and overall size = 1
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Init processors
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: DEBUG: Pair is not in synchronized state (version issue): StateRow[4](Local:/Nuxeo Drive Test Workspace/Test folder/joe.odt, Remote:defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42, State: remotely_created)
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Finish <bound method Processor._synchronize_remotely_created of <nxdrive.engine.processor.Processor object at 0x7f58c52b3348>> on doc pair StateRow[4](Local:/Nuxeo Drive Test Workspace/Test folder/joe.odt, Remote:defaultFileSystemItemFactory#default#219197f4-dd5f-47ad-b40e-e4645fc86c42, State: remotely_created)
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Released processor 140018517260032
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Acquired processor 140018517260032 for row 5
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Calling <bound method Processor._synchronize_remotely_created of <nxdrive.engine.processor.Processor object at 0x7f58c52b3348>> on doc pair StateRow[5](Local:/Nuxeo Drive Test Workspace/Test folder/jack.odt, Remote:defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc, State: remotely_created)
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: DEBUG: Creating local file 'jack.odt' in '/tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder'
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc', 'parentId': u'defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5'}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc", "parentId": "defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5"}}'
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"downloadURL":"nxbigfile/default/7d185c40-c030-410a-8a37-fe432b46c6bc/blobholder:0/jack.odt","canUpdate":false,"digestAlgorithm":"md5","digest":"b53227da4280f0e18270f21dd77c91d0","creationDate":1424632469200,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469241,"canDelete":false,"name":"jack.odt","id":"defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","userName":"nuxeoDriveTestUser_user_1"}'
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/7d185c40-c030-410a-8a37-fe432b46c6bc/blobholder:0/jack.odt' with headers: {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Transfer speed 0 ko/s
      20:14:34 [INFO]      [exec] nxdrive.client.local_client: TRACE: Setting xattr ndrive with value defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/jack.odt
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Finish <bound method Processor._synchronize_remotely_created of <nxdrive.engine.processor.Processor object at 0x7f58c52b3348>> on doc pair StateRow[5](Local:/Nuxeo Drive Test Workspace/Test folder/jack.odt, Remote:defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc, State: remotely_created)
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Released processor 140018517260032
      20:14:34 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread RemoteFileProcessor(140018517260032) end
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.WaitForAsyncCompletion' with cookies [] has content-type ''
      20:14:34 [INFO]      [exec] nxdrive.tests.common_unit_test: DEBUG: Wait for sync
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event created on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Pushing QueueItem[3](Folderish:1, State: locally_modified)
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: creating local folder processor
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace
      20:14:34 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread LocalFolderProcessor(140018517260032) start
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'} and cookies []
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Acquired processor 140018517260032 for row 3
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Skip as pair is None or in non-processable state: StateRow[3](Local:/Nuxeo Drive Test Workspace/Test folder, Remote:defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5, State: synchronized)
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Released processor 140018517260032
      20:14:34 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread LocalFolderProcessor(140018517260032) end
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event created on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/.joe.odt.nxpart
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/.joe.odt.nxpart
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event moved on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/.joe.odt.nxpart
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/joe.odt
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event created on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/.jack.odt.nxpart
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/.jack.odt.nxpart
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event moved on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/.jack.odt.nxpart
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.local_watcher: DEBUG: handle_watchdog_event modified on /tmp/tmpOXXhLi-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Test folder/jack.odt
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Pushing QueueItem[5](Folderish:0, State: locally_modified)
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: creating local file processor
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread LocalFileProcessor(140018517260032) start
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'} and cookies []
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Acquired processor 140018517260032 for row 5
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc'}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc"}}'
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies []: '{"downloadURL":"nxbigfile/default/7d185c40-c030-410a-8a37-fe432b46c6bc/blobholder:0/jack.odt","canUpdate":false,"digestAlgorithm":"md5","digest":"b53227da4280f0e18270f21dd77c91d0","creationDate":1424632469200,"creator":"nuxeoDriveTestUser_user_1","folder":false,"parentId":"defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5","lastContributor":"nuxeoDriveTestUser_user_1","canRename":false,"lastModificationDate":1424632469241,"canDelete":false,"name":"jack.odt","id":"defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#fd1c386b-9150-4463-85a0-c6b477ff580f/defaultFileSystemItemFactory#default#e54ce31a-8f39-4898-bdb7-7a373f5624f5/defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc","userName":"nuxeoDriveTestUser_user_1"}'
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Calling <bound method Processor._synchronize_locally_modified of <nxdrive.engine.processor.Processor object at 0x7f58c5252050>> on doc pair StateRow[5](Local:/Nuxeo Drive Test Workspace/Test folder/jack.odt, Remote:defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc, State: locally_modified)
      20:14:34 [INFO]      [exec] nxdrive.engine.processor: TRACE: Finish <bound method Processor._synchronize_locally_modified of <nxdrive.engine.processor.Processor object at 0x7f58c5252050>> on doc pair StateRow[5](Local:/Nuxeo Drive Test Workspace/Test folder/jack.odt, Remote:defaultFileSystemItemFactory#default#7d185c40-c030-410a-8a37-fe432b46c6bc, State: locally_modified)
      20:14:34 [INFO]      [exec] nxdrive.engine.dao.sqlite: TRACE: Released processor 140018517260032
      20:14:34 [INFO]      [exec] nxdrive.engine.workers: DEBUG: Thread LocalFileProcessor(140018517260032) end
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.watcher.remote_watcher: DEBUG: Handle remote changes
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'lowerBound': 2683, 'lastSyncActiveRootDefinitions': u'default:fd1c386b-9150-4463-85a0-c6b477ff580f'}}
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary with headers {'X-Authentication-Token': u'4e2c41d8-ed8b-492c-b5ba-e1e7800a2eeb', 'X-NXDocumentProperties': '*', 'X-Device-Id': '0122c0eabac711e4b931404062563b44', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/test', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': 'test'}, cookies [] and JSON payload '{"params": {"lowerBound": 2683, "lastSyncActiveRootDefinitions": "default:fd1c386b-9150-4463-85a0-c6b477ff580f"}}'
      20:14:34 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChangeSummary' with cookies []: '{"activeSynchronizationRootDefinitions":"default:fd1c386b-9150-4463-85a0-c6b477ff580f","syncDate":1424632472000,"hasTooManyChanges":false,"upperBound":2695,"fileSystemChanges":[]}'
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: Active: LocalFolder: None, LocalFile: None, RemoteFolder: None, RemoteFile: None, Pool:0
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.engine: DEBUG: Checking sync completed: queue manager is inactive and overall size = 0
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: DEBUG: Active: LocalFolder: None, LocalFile: None, RemoteFolder: None, RemoteFile: None, Pool:0
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.engine.queue_manager: TRACE: Launch processors
      20:14:34 [INFO]      [exec] nxdrive.tests.common_unit_test: DEBUG: Sync completed
      20:14:34 [INFO]      [exec] --------------------- >> end captured logging << ---------------------
      20:14:34 [INFO]      [exec] ----------------------------------------------------------------------
      

        Attachments

          Issue Links

            Activity

              People

              • Assignee:
                ataillefer Antoine Taillefer
                Reporter:
                ataillefer Antoine Taillefer
                Participants:
              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: