Uploaded image for project: 'Nuxeo Platform'
  1. Nuxeo Platform
  2. NXP-13227

Drive: investigate on randomly failing IT tests due to org.h2.jdbc.JdbcSQLException: Deadlock detected

    XMLWordPrintable

    Details

      Description

      For example:

      01:53:55 ERROR: test_binding_synchronization_empty_start (nxdrive.tests.test_integration_synchronization.TestIntegrationSynchronization)
      01:53:55 ----------------------------------------------------------------------
      01:53:55 Traceback (most recent call last):
      01:53:55   File "/home/hudson/tmp/workspace/IT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive/tests/test_integration_synchronization.py", line 244, in test_binding_synchronization_empty_start
      01:53:55     remote_client.make_file(f3, 'File 6.txt', content='ffff')
      01:53:55   File "/home/hudson/tmp/workspace/IT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive/client/remote_document_client.py", line 150, in make_file
      01:53:55     properties={'dc:title': name})
      01:53:55   File "/home/hudson/tmp/workspace/IT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive/client/remote_document_client.py", line 306, in create
      01:53:55     type=doc_type, name=name, properties=properties)
      01:53:55   File "/home/hudson/tmp/workspace/IT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive/client/base_automation_client.py", line 288, in execute
      01:53:55     resp = self.opener.open(req, timeout=timeout)
      01:53:55   File "/usr/lib/python2.7/urllib2.py", line 406, in open
      01:53:55     response = meth(req, response)
      01:53:55   File "/usr/lib/python2.7/urllib2.py", line 519, in http_response
      01:53:55     'http', request, response, code, msg, hdrs)
      01:53:55   File "/usr/lib/python2.7/urllib2.py", line 444, in error
      01:53:55     return self._call_chain(*args)
      01:53:55   File "/usr/lib/python2.7/urllib2.py", line 378, in _call_chain
      01:53:55     result = func(*args)
      01:53:55   File "/usr/lib/python2.7/urllib2.py", line 527, in http_error_default
      01:53:55     raise HTTPError(req.get_full_url(), code, msg, hdrs, fp)
      01:53:55 HTTPError: HTTP Error 500: Internal Server Error
      01:53:55 -------------------- >> begin captured logging << --------------------
      01:53:55 nxdrive.controller: DEBUG: nxdrive installed in '/home/hudson/tmp/workspace/IT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive'
      01:53:55 nxdrive.controller: DEBUG: nxdrive configured in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/nuxeo-drive-conf'
      01:53:55 nxdrive.model: DEBUG: Set client version to 1.2-dev
      01:53:55 nxdrive.controller: DEBUG: nxdrive installed in '/home/hudson/tmp/workspace/IT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive'
      01:53:55 nxdrive.controller: DEBUG: nxdrive configured in '/tmp/tmptt0DY9-nxdrive-tests-user-2/nuxeo-drive-conf'
      01:53:55 nxdrive.model: DEBUG: Set client version to 1.2-dev
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-administrator-device', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'} and cookies []
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"value": "/"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"f5df873e-9497-443f-8dbc-3fd6d6c8b79c","path":"/","type":"Root","state":null,"versionLabel":"","isCheckedOut":true,"title":"f5df873e-9497-443f-8dbc-3fd6d6c8b79c","properties":{"dc:creator":null,"dc:source":null,"dc:nature":null,"dc:contributors":[],"dc:created":null,"dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":null,"dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":null,"dc:lastContributor":null,"common:icon":null,"common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":null,"contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'userNames': 'user_1, user_2', 'permission': 'ReadWrite'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"userNames": "user_1, user_2", "permission": "ReadWrite"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests' with cookies [] and content-type: 'text/plain'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/default-domain/workspaces/nuxeo-drive-test-workspace'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"value": "/default-domain/workspaces/nuxeo-drive-test-workspace"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"9da74aa4-7ab6-45af-b0fa-4812644e21b0","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2013-12-12T00:51:03.43Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:nature":null,"dc:contributors":["Administrator"],"dc:created":"2013-12-12T00:51:03.43Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.43Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Nuxeo Drive Test Workspace","dc:lastContributor":"Administrator","files:files":[],"common:icon":"/icons/workspace.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"webc:welcomeText":null,"webc:useCaptcha":null,"webc:welcomeMedia":null,"webc:theme":"sites","webc:isWebContainer":null,"webc:baseline":null,"webc:template":null,"webc:logo":null,"webc:themePerspective":null,"webc:themePage":"workspace","webc:name":null,"webc:moderationType":"aposteriori","webc:url":null,"webc:email":null,"publish:sections":[]},"facets":["SuperSpace","Folderish"],"changeToken":"1386809463436","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='} and cookies []
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'9da74aa4-7ab6-45af-b0fa-4812644e21b0'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"value": "9da74aa4-7ab6-45af-b0fa-4812644e21b0"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"9da74aa4-7ab6-45af-b0fa-4812644e21b0","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2013-12-12T00:51:03.43Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:nature":null,"dc:contributors":["Administrator"],"dc:created":"2013-12-12T00:51:03.43Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.43Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Nuxeo Drive Test Workspace","dc:lastContributor":"Administrator","files:files":[],"common:icon":"/icons/workspace.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"webc:welcomeText":null,"webc:useCaptcha":null,"webc:welcomeMedia":null,"webc:theme":"sites","webc:isWebContainer":null,"webc:baseline":null,"webc:template":null,"webc:logo":null,"webc:themePerspective":null,"webc:themePage":"workspace","webc:name":null,"webc:moderationType":"aposteriori","webc:url":null,"webc:email":null,"publish:sections":[]},"facets":["SuperSpace","Folderish"],"changeToken":"1386809463436","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-2', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo2NzkwMTE='} and cookies []
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'9da74aa4-7ab6-45af-b0fa-4812644e21b0'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-2', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo2NzkwMTE='}, cookies [] and JSON payload '{"params": {"value": "9da74aa4-7ab6-45af-b0fa-4812644e21b0"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"9da74aa4-7ab6-45af-b0fa-4812644e21b0","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2013-12-12T00:51:03.43Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:nature":null,"dc:contributors":["Administrator"],"dc:created":"2013-12-12T00:51:03.43Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.43Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Nuxeo Drive Test Workspace","dc:lastContributor":"Administrator","files:files":[],"common:icon":"/icons/workspace.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"webc:welcomeText":null,"webc:useCaptcha":null,"webc:welcomeMedia":null,"webc:theme":"sites","webc:isWebContainer":null,"webc:baseline":null,"webc:template":null,"webc:logo":null,"webc:themePerspective":null,"webc:themePage":"workspace","webc:name":null,"webc:moderationType":"aposteriori","webc:url":null,"webc:email":null,"publish:sections":[]},"facets":["SuperSpace","Folderish"],"changeToken":"1386809463436","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='} and cookies []
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-2', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo2NzkwMTE='} and cookies []
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.2-dev', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='} and cookies []
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/authentication/token?applicationName=Nuxeo+Drive&deviceDescription=Linux+Desktop&revoke=false&deviceId=7911aca062c711e3bdca00219b008ad3&permission=ReadWrite with headers {'X-Client-Version': '1.2-dev', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='} and cookies []
      01:53:55 nxdrive.client.base_automation_client: TRACE: Got token '517708ce-0a08-4bcc-ad07-a379abfcdbdb' with cookies []
      01:53:55 nxdrive.controller: INFO: Binding '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive' to 'http://localhost:8080/nuxeo/' with account 'nuxeoDriveTestUser_user_1'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'} and cookies []
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetTopLevelFolder' with cookies [] and JSON payload: '{"canCreateChild":false,"creationDate":603,"canDelete":false,"lastModificationDate":603,"canRename":false,"creator":"system","parentId":null,"folder":true,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/', remote_name=None, local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '1970-01-01 01:00:00'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 1970-01-01 01:00:00
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/', remote_name=u'Nuxeo Drive', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Authentication-Token': u'517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'} and cookies []
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:9da74aa4-7ab6-45af-b0fa-4812644e21b0', 'params': {'enable': True}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization with headers {'X-Authentication-Token': u'517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"input": "doc:9da74aa4-7ab6-45af-b0fa-4812644e21b0", "params": {"enable": true}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetSynchronization' with cookies [] and content-type: ''
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:9da74aa4-7ab6-45af-b0fa-4812644e21b0', 'params': {'type': 'Folder', 'name': u'Folder 1', 'properties': u'dc:title=Folder 1'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:9da74aa4-7ab6-45af-b0fa-4812644e21b0", "params": {"type": "Folder", "name": "Folder 1", "properties": "dc:title=Folder 1"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"a42412f5-7c3f-431e-b263-ff4150426d6e","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Folder 1","lastModified":"2013-12-12T00:51:03.83Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:03.83Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.83Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Folder 1","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1386809463832","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:a42412f5-7c3f-431e-b263-ff4150426d6e', 'params': {'type': 'Folder', 'name': u'Folder 1.1', 'properties': u'dc:title=Folder 1.1'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:a42412f5-7c3f-431e-b263-ff4150426d6e", "params": {"type": "Folder", "name": "Folder 1.1", "properties": "dc:title=Folder 1.1"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Folder 1.1","lastModified":"2013-12-12T00:51:03.84Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:03.84Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.84Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Folder 1.1","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1386809463844","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:a42412f5-7c3f-431e-b263-ff4150426d6e', 'params': {'type': 'Folder', 'name': u'Folder 1.2', 'properties': u'dc:title=Folder 1.2'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:a42412f5-7c3f-431e-b263-ff4150426d6e", "params": {"type": "Folder", "name": "Folder 1.2", "properties": "dc:title=Folder 1.2"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"77d9201a-1f33-423a-9fbd-67737499c5ea","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.2","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Folder 1.2","lastModified":"2013-12-12T00:51:03.86Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:03.86Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.86Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Folder 1.2","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1386809463865","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:9da74aa4-7ab6-45af-b0fa-4812644e21b0', 'params': {'type': 'Folder', 'name': u'Folder 2', 'properties': u'dc:title=Folder 2'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:9da74aa4-7ab6-45af-b0fa-4812644e21b0", "params": {"type": "Folder", "name": "Folder 2", "properties": "dc:title=Folder 2"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"73455c7c-edaf-4db3-bd39-77f8c711549a","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 2","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Folder 2","lastModified":"2013-12-12T00:51:03.88Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:03.88Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.88Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Folder 2","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1386809463881","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:73455c7c-edaf-4db3-bd39-77f8c711549a', 'params': {'type': 'File', 'name': u'Duplicated File.txt', 'properties': u'dc:title=Duplicated File.txt'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:73455c7c-edaf-4db3-bd39-77f8c711549a", "params": {"type": "File", "name": "Duplicated File.txt", "properties": "dc:title=Duplicated File.txt"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"64b98c37-6fb0-4169-80ed-547c434e8430","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 2/Duplicated File.txt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"Duplicated File.txt","lastModified":"2013-12-12T00:51:03.89Z","properties":{"uid:uid":null,"uid:minor_version":"0","uid:major_version":"0","dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:03.89Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.89Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Duplicated File.txt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"common:icon":"/icons/file.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","Versionable","Publishable","HasRelatedText"],"changeToken":"1386809463897","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 13, 'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 13, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1386809463.91_861684109', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'Duplicated%20File.txt'} and cookies [] for file /tmp/tmpQtCkm8-nxdrive-uploads/tmpNtFzYT-nxdrive-file-to-upload
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies [] and JSON payload: '{"uploaded":"true","batchId":"1386809463.91_861684109"}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1386809463.91_861684109', 'document': u'64b98c37-6fb0-4169-80ed-547c434e8430', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"batchId": "1386809463.91_861684109", "document": "64b98c37-6fb0-4169-80ed-547c434e8430", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] and content-type: 'text/plain'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:73455c7c-edaf-4db3-bd39-77f8c711549a', 'params': {'type': 'File', 'name': u'Duplicated File.txt', 'properties': u'dc:title=Duplicated File.txt'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:73455c7c-edaf-4db3-bd39-77f8c711549a", "params": {"type": "File", "name": "Duplicated File.txt", "properties": "dc:title=Duplicated File.txt"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"97dcf691-f291-4761-8be1-371f5134e3f9","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 2/Duplicated File.txt.1386809463936","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"Duplicated File.txt","lastModified":"2013-12-12T00:51:03.93Z","properties":{"uid:uid":null,"uid:minor_version":"0","uid:major_version":"0","dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:03.93Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.93Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Duplicated File.txt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"common:icon":"/icons/file.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","Versionable","Publishable","HasRelatedText"],"changeToken":"1386809463937","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 14, 'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 14, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1386809463.95_867292454', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'Duplicated%20File.txt'} and cookies [] for file /tmp/tmpQtCkm8-nxdrive-uploads/tmpNIHAHi-nxdrive-file-to-upload
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies [] and JSON payload: '{"uploaded":"true","batchId":"1386809463.95_867292454"}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1386809463.95_867292454', 'document': u'97dcf691-f291-4761-8be1-371f5134e3f9', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"batchId": "1386809463.95_867292454", "document": "97dcf691-f291-4761-8be1-371f5134e3f9", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] and content-type: 'text/plain'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:a42412f5-7c3f-431e-b263-ff4150426d6e', 'params': {'type': 'File', 'name': u'File 1.txt', 'properties': u'dc:title=File 1.txt'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:a42412f5-7c3f-431e-b263-ff4150426d6e", "params": {"type": "File", "name": "File 1.txt", "properties": "dc:title=File 1.txt"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"54fa6347-790a-4ed3-8868-fe6100e56b48","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/File 1.txt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"File 1.txt","lastModified":"2013-12-12T00:51:03.97Z","properties":{"uid:uid":null,"uid:minor_version":"0","uid:major_version":"0","dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:03.97Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.97Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"File 1.txt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"common:icon":"/icons/file.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","Versionable","Publishable","HasRelatedText"],"changeToken":"1386809463977","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 3, 'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 3, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1386809463.98_495541476', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'File%201.txt'} and cookies [] for file /tmp/tmpQtCkm8-nxdrive-uploads/tmpG5ssbg-nxdrive-file-to-upload
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies [] and JSON payload: '{"uploaded":"true","batchId":"1386809463.98_495541476"}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1386809463.98_495541476', 'document': u'54fa6347-790a-4ed3-8868-fe6100e56b48', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"batchId": "1386809463.98_495541476", "document": "54fa6347-790a-4ed3-8868-fe6100e56b48", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] and content-type: 'text/plain'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:e366ed9b-f3e3-4be5-8393-95f4c0ddb73d', 'params': {'type': 'File', 'name': u'File 2.txt', 'properties': u'dc:title=File 2.txt'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:e366ed9b-f3e3-4be5-8393-95f4c0ddb73d", "params": {"type": "File", "name": "File 2.txt", "properties": "dc:title=File 2.txt"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"29e7fe14-0207-424a-bf77-c906faffb92d","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1/File 2.txt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"File 2.txt","lastModified":"2013-12-12T00:51:04.02Z","properties":{"uid:uid":null,"uid:minor_version":"0","uid:major_version":"0","dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:04.02Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:04.02Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"File 2.txt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"common:icon":"/icons/file.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","Versionable","Publishable","HasRelatedText"],"changeToken":"1386809464022","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 3, 'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 3, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1386809464.04_369354796', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'File%202.txt'} and cookies [] for file /tmp/tmpQtCkm8-nxdrive-uploads/tmp9tWpBp-nxdrive-file-to-upload
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies [] and JSON payload: '{"uploaded":"true","batchId":"1386809464.04_369354796"}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1386809464.04_369354796', 'document': u'29e7fe14-0207-424a-bf77-c906faffb92d', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"batchId": "1386809464.04_369354796", "document": "29e7fe14-0207-424a-bf77-c906faffb92d", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] and content-type: 'text/plain'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:77d9201a-1f33-423a-9fbd-67737499c5ea', 'params': {'type': 'File', 'name': u'File 3.txt', 'properties': u'dc:title=File 3.txt'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:77d9201a-1f33-423a-9fbd-67737499c5ea", "params": {"type": "File", "name": "File 3.txt", "properties": "dc:title=File 3.txt"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"ba2e36b6-b01d-4988-93ff-f243312c6617","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.2/File 3.txt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"File 3.txt","lastModified":"2013-12-12T00:51:04.09Z","properties":{"uid:uid":null,"uid:minor_version":"0","uid:major_version":"0","dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:04.09Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:04.09Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"File 3.txt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"common:icon":"/icons/file.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","Versionable","Publishable","HasRelatedText"],"changeToken":"1386809464092","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 3, 'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 3, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1386809464.1_419714390', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'File%203.txt'} and cookies [] for file /tmp/tmpQtCkm8-nxdrive-uploads/tmp3aYgGV-nxdrive-file-to-upload
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies [] and JSON payload: '{"uploaded":"true","batchId":"1386809464.1_419714390"}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1386809464.1_419714390', 'document': u'ba2e36b6-b01d-4988-93ff-f243312c6617', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"batchId": "1386809464.1_419714390", "document": "ba2e36b6-b01d-4988-93ff-f243312c6617", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] and content-type: 'text/plain'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:73455c7c-edaf-4db3-bd39-77f8c711549a', 'params': {'type': 'File', 'name': u'File 4.txt', 'properties': u'dc:title=File 4.txt'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:73455c7c-edaf-4db3-bd39-77f8c711549a", "params": {"type": "File", "name": "File 4.txt", "properties": "dc:title=File 4.txt"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"9e754b43-a951-45a8-bc69-25db70a15b5f","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 2/File 4.txt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"File 4.txt","lastModified":"2013-12-12T00:51:04.12Z","properties":{"uid:uid":null,"uid:minor_version":"0","uid:major_version":"0","dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:04.12Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:04.12Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"File 4.txt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"common:icon":"/icons/file.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","Versionable","Publishable","HasRelatedText"],"changeToken":"1386809464125","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 3, 'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 3, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1386809464.13_392599900', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'File%204.txt'} and cookies [] for file /tmp/tmpQtCkm8-nxdrive-uploads/tmpuESNVq-nxdrive-file-to-upload
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies [] and JSON payload: '{"uploaded":"true","batchId":"1386809464.13_392599900"}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1386809464.13_392599900', 'document': u'9e754b43-a951-45a8-bc69-25db70a15b5f', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"batchId": "1386809464.13_392599900", "document": "9e754b43-a951-45a8-bc69-25db70a15b5f", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] and content-type: 'text/plain'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:9da74aa4-7ab6-45af-b0fa-4812644e21b0', 'params': {'type': 'File', 'name': u'File 5.txt', 'properties': u'dc:title=File 5.txt'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:9da74aa4-7ab6-45af-b0fa-4812644e21b0", "params": {"type": "File", "name": "File 5.txt", "properties": "dc:title=File 5.txt"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"4e24eea4-6735-48ec-9abb-9fbcaf03aeee","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/File 5.txt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"File 5.txt","lastModified":"2013-12-12T00:51:04.16Z","properties":{"uid:uid":null,"uid:minor_version":"0","uid:major_version":"0","dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:04.16Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:04.16Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"File 5.txt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"common:icon":"/icons/file.gif","common:icon-expanded":null,"common:size":null,"file:content":null,"file:filename":null,"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","Versionable","Publishable","HasRelatedText"],"changeToken":"1386809464166","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 3, 'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 3, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1386809464.18_957813262', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'File%205.txt'} and cookies [] for file /tmp/tmpQtCkm8-nxdrive-uploads/tmpUiyCR2-nxdrive-file-to-upload
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies [] and JSON payload: '{"uploaded":"true","batchId":"1386809464.18_957813262"}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1386809464.18_957813262', 'document': u'4e24eea4-6735-48ec-9abb-9fbcaf03aeee', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"batchId": "1386809464.18_957813262", "document": "4e24eea4-6735-48ec-9abb-9fbcaf03aeee", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] and content-type: 'text/plain'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"canCreateChild":false,"creationDate":223,"canDelete":false,"lastModificationDate":223,"canRename":false,"creator":"system","parentId":null,"folder":true,"name":"Nuxeo Drive","id":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '1970-01-01 01:00:00', '1970-01-01 01:00:00'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"canCreateChild":true,"creationDate":1386809463436,"canDelete":true,"lastModificationDate":1386809463813,"canRename":true,"creator":"Administrator","parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","folder":true,"name":"Nuxeo Drive Test Workspace","id":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0'])
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:03
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Nuxeo Drive Test Workspace', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Nuxeo Drive Test Workspace', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"canCreateChild":true,"creationDate":1386809463832,"canDelete":true,"lastModificationDate":1386809463832,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","folder":true,"name":"Folder 1","id":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","userName":"nuxeoDriveTestUser_user_1"},{"canCreateChild":true,"creationDate":1386809463881,"canDelete":true,"lastModificationDate":1386809463881,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","folder":true,"name":"Folder 2","id":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","userName":"nuxeoDriveTestUser_user_1"},{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/4e24eea4-6735-48ec-9abb-9fbcaf03aeee/blobholder:0/File%205.txt","digest":"d2f2297d6e829cd3493aa7de4416a18f","creationDate":1386809464166,"canDelete":true,"lastModificationDate":1386809464194,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","folder":false,"name":"File 5.txt","id":"defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee', u'defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a', u'defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e'])
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:03
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Folder 1', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Folder 1', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"canCreateChild":true,"creationDate":1386809463844,"canDelete":true,"lastModificationDate":1386809463844,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","folder":true,"name":"Folder 1.1","id":"defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","userName":"nuxeoDriveTestUser_user_1"},{"canCreateChild":true,"creationDate":1386809463865,"canDelete":true,"lastModificationDate":1386809463865,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","folder":true,"name":"Folder 1.2","id":"defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea","userName":"nuxeoDriveTestUser_user_1"},{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/54fa6347-790a-4ed3-8868-fe6100e56b48/blobholder:0/File%201.txt","digest":"47bce5c74f589f4867dbd57e9ca9f808","creationDate":1386809463977,"canDelete":true,"lastModificationDate":1386809464002,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","folder":false,"name":"File 1.txt","id":"defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea', u'defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d', u'defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48'])
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:03
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Folder 1.1', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Folder 1.1', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/29e7fe14-0207-424a-bf77-c906faffb92d/blobholder:0/File%202.txt","digest":"08f8e0260c64418510cefb2b06eee5cd","creationDate":1386809464022,"canDelete":true,"lastModificationDate":1386809464074,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","folder":false,"name":"File 2.txt","id":"defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d/defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d'])
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:04
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'File 2.txt', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'File 2.txt', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:04', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:03
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Folder 1.2', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Folder 1.2', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/ba2e36b6-b01d-4988-93ff-f243312c6617/blobholder:0/File%203.txt","digest":"9df62e693988eb4e1e1444ece0578579","creationDate":1386809464092,"canDelete":true,"lastModificationDate":1386809464114,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea","folder":false,"name":"File 3.txt","id":"defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea/defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617'])
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:04
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'File 3.txt', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'File 3.txt', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:04', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:04
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'File 1.txt', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'File 1.txt', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:04', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:03
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Folder 2', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Folder 2', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/64b98c37-6fb0-4169-80ed-547c434e8430/blobholder:0/Duplicated%20File.txt","digest":"b8ab309a6b9a3f448092a136afa8fa25","creationDate":1386809463897,"canDelete":true,"lastModificationDate":1386809463922,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"Duplicated File.txt","id":"defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430","userName":"nuxeoDriveTestUser_user_1"},{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/97dcf691-f291-4761-8be1-371f5134e3f9/blobholder:0/Duplicated%20File.txt","digest":"39181c49e54b6e5ae8be13ab66f9fdb8","creationDate":1386809463937,"canDelete":true,"lastModificationDate":1386809463960,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"Duplicated File.txt","id":"defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9","userName":"nuxeoDriveTestUser_user_1"},{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/9e754b43-a951-45a8-bc69-25db70a15b5f/blobholder:0/File%204.txt","digest":"77963b7a931377ad4ab5ad6a9cd718aa","creationDate":1386809464125,"canDelete":true,"lastModificationDate":1386809464146,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"File 4.txt","id":"defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9', u'defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f', u'defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430'])
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:03
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Duplicated File.txt', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Duplicated File.txt', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:03
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Duplicated File.txt', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'Duplicated File.txt', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:04
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'File 4.txt', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'File 4.txt', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:04', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = 'None', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: last_remote_updated is None for doc None, set it to 2013-12-12 01:51:04
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'File 5.txt', local_state=None, remote_state=None, pair_state='unknown'>
      01:53:55 nxdrive.synchronizer: TRACE: Created new pair LastKnownState<local_folder=u'Nuxeo Drive', local_path=None, remote_name=u'File 5.txt', local_state='unknown', remote_state='unknown', pair_state='unknown'>
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:04', '2013-12-12 01:51:04'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"canCreateChild":true,"creationDate":1386809463436,"canDelete":true,"lastModificationDate":1386809463813,"canRename":true,"creator":"Administrator","parentId":"org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#","folder":true,"name":"Nuxeo Drive Test Workspace","id":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Nuxeo Drive Test Workspace', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local folder 'Nuxeo Drive Test Workspace' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/'
      01:53:55 nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Nuxeo Drive Test Workspace
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"canCreateChild":true,"creationDate":1386809463832,"canDelete":true,"lastModificationDate":1386809463832,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","folder":true,"name":"Folder 1","id":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","userName":"nuxeoDriveTestUser_user_1"},{"canCreateChild":true,"creationDate":1386809463881,"canDelete":true,"lastModificationDate":1386809463881,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","folder":true,"name":"Folder 2","id":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","userName":"nuxeoDriveTestUser_user_1"},{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/4e24eea4-6735-48ec-9abb-9fbcaf03aeee/blobholder:0/File%205.txt","digest":"d2f2297d6e829cd3493aa7de4416a18f","creationDate":1386809464166,"canDelete":true,"lastModificationDate":1386809464194,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","folder":false,"name":"File 5.txt","id":"defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee', u'defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a', u'defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e'])
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace', remote_name=u'Nuxeo Drive Test Workspace', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/4e24eea4-6735-48ec-9abb-9fbcaf03aeee/blobholder:0/File%205.txt","digest":"d2f2297d6e829cd3493aa7de4416a18f","creationDate":1386809464166,"canDelete":true,"lastModificationDate":1386809464194,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","folder":false,"name":"File 5.txt","id":"defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:04', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'File 5.txt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local file 'File 5.txt' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/4e24eea4-6735-48ec-9abb-9fbcaf03aeee/blobholder:0/File%205.txt","digest":"d2f2297d6e829cd3493aa7de4416a18f","creationDate":1386809464166,"canDelete":true,"lastModificationDate":1386809464194,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","folder":false,"name":"File 5.txt","id":"defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#4e24eea4-6735-48ec-9abb-9fbcaf03aeee","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/4e24eea4-6735-48ec-9abb-9fbcaf03aeee/blobholder:0/File%205.txt' with headers: {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/File 5.txt', remote_name=u'File 5.txt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"canCreateChild":true,"creationDate":1386809463832,"canDelete":true,"lastModificationDate":1386809463832,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","folder":true,"name":"Folder 1","id":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Folder 1', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local folder 'Folder 1' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'
      01:53:55 nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Folder 1
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"canCreateChild":true,"creationDate":1386809463844,"canDelete":true,"lastModificationDate":1386809463844,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","folder":true,"name":"Folder 1.1","id":"defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","userName":"nuxeoDriveTestUser_user_1"},{"canCreateChild":true,"creationDate":1386809463865,"canDelete":true,"lastModificationDate":1386809463865,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","folder":true,"name":"Folder 1.2","id":"defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea","userName":"nuxeoDriveTestUser_user_1"},{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/54fa6347-790a-4ed3-8868-fe6100e56b48/blobholder:0/File%201.txt","digest":"47bce5c74f589f4867dbd57e9ca9f808","creationDate":1386809463977,"canDelete":true,"lastModificationDate":1386809464002,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","folder":false,"name":"File 1.txt","id":"defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea', u'defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d', u'defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48'])
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Folder 1', remote_name=u'Folder 1', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"canCreateChild":true,"creationDate":1386809463881,"canDelete":true,"lastModificationDate":1386809463881,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0","folder":true,"name":"Folder 2","id":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Folder 2', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local folder 'Folder 2' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace'
      01:53:55 nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Folder 2
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/64b98c37-6fb0-4169-80ed-547c434e8430/blobholder:0/Duplicated%20File.txt","digest":"b8ab309a6b9a3f448092a136afa8fa25","creationDate":1386809463897,"canDelete":true,"lastModificationDate":1386809463922,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"Duplicated File.txt","id":"defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430","userName":"nuxeoDriveTestUser_user_1"},{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/97dcf691-f291-4761-8be1-371f5134e3f9/blobholder:0/Duplicated%20File.txt","digest":"39181c49e54b6e5ae8be13ab66f9fdb8","creationDate":1386809463937,"canDelete":true,"lastModificationDate":1386809463960,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"Duplicated File.txt","id":"defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9","userName":"nuxeoDriveTestUser_user_1"},{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/9e754b43-a951-45a8-bc69-25db70a15b5f/blobholder:0/File%204.txt","digest":"77963b7a931377ad4ab5ad6a9cd718aa","creationDate":1386809464125,"canDelete":true,"lastModificationDate":1386809464146,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"File 4.txt","id":"defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9', u'defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f', u'defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430'])
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Folder 2', remote_name=u'Folder 2', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/64b98c37-6fb0-4169-80ed-547c434e8430/blobholder:0/Duplicated%20File.txt","digest":"b8ab309a6b9a3f448092a136afa8fa25","creationDate":1386809463897,"canDelete":true,"lastModificationDate":1386809463922,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"Duplicated File.txt","id":"defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Duplicated File.txt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local file 'Duplicated File.txt' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Folder 2'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/64b98c37-6fb0-4169-80ed-547c434e8430/blobholder:0/Duplicated%20File.txt","digest":"b8ab309a6b9a3f448092a136afa8fa25","creationDate":1386809463897,"canDelete":true,"lastModificationDate":1386809463922,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"Duplicated File.txt","id":"defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#64b98c37-6fb0-4169-80ed-547c434e8430","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/64b98c37-6fb0-4169-80ed-547c434e8430/blobholder:0/Duplicated%20File.txt' with headers: {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Folder 2/Duplicated File.txt', remote_name=u'Duplicated File.txt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/97dcf691-f291-4761-8be1-371f5134e3f9/blobholder:0/Duplicated%20File.txt","digest":"39181c49e54b6e5ae8be13ab66f9fdb8","creationDate":1386809463937,"canDelete":true,"lastModificationDate":1386809463960,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"Duplicated File.txt","id":"defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Duplicated File.txt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local file 'Duplicated File__1.txt' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Folder 2'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/97dcf691-f291-4761-8be1-371f5134e3f9/blobholder:0/Duplicated%20File.txt","digest":"39181c49e54b6e5ae8be13ab66f9fdb8","creationDate":1386809463937,"canDelete":true,"lastModificationDate":1386809463960,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"Duplicated File.txt","id":"defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#97dcf691-f291-4761-8be1-371f5134e3f9","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/97dcf691-f291-4761-8be1-371f5134e3f9/blobholder:0/Duplicated%20File.txt' with headers: {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Folder 2/Duplicated File__1.txt', remote_name=u'Duplicated File.txt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/9e754b43-a951-45a8-bc69-25db70a15b5f/blobholder:0/File%204.txt","digest":"77963b7a931377ad4ab5ad6a9cd718aa","creationDate":1386809464125,"canDelete":true,"lastModificationDate":1386809464146,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"File 4.txt","id":"defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:04', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'File 4.txt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local file 'File 4.txt' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Folder 2'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/9e754b43-a951-45a8-bc69-25db70a15b5f/blobholder:0/File%204.txt","digest":"77963b7a931377ad4ab5ad6a9cd718aa","creationDate":1386809464125,"canDelete":true,"lastModificationDate":1386809464146,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a","folder":false,"name":"File 4.txt","id":"defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#73455c7c-edaf-4db3-bd39-77f8c711549a/defaultFileSystemItemFactory#default#9e754b43-a951-45a8-bc69-25db70a15b5f","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/9e754b43-a951-45a8-bc69-25db70a15b5f/blobholder:0/File%204.txt' with headers: {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Folder 2/File 4.txt', remote_name=u'File 4.txt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/54fa6347-790a-4ed3-8868-fe6100e56b48/blobholder:0/File%201.txt","digest":"47bce5c74f589f4867dbd57e9ca9f808","creationDate":1386809463977,"canDelete":true,"lastModificationDate":1386809464002,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","folder":false,"name":"File 1.txt","id":"defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:04', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'File 1.txt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local file 'File 1.txt' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Folder 1'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/54fa6347-790a-4ed3-8868-fe6100e56b48/blobholder:0/File%201.txt","digest":"47bce5c74f589f4867dbd57e9ca9f808","creationDate":1386809463977,"canDelete":true,"lastModificationDate":1386809464002,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","folder":false,"name":"File 1.txt","id":"defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#54fa6347-790a-4ed3-8868-fe6100e56b48","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/54fa6347-790a-4ed3-8868-fe6100e56b48/blobholder:0/File%201.txt' with headers: {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Folder 1/File 1.txt', remote_name=u'File 1.txt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"canCreateChild":true,"creationDate":1386809463844,"canDelete":true,"lastModificationDate":1386809463844,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","folder":true,"name":"Folder 1.1","id":"defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Folder 1.1', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local folder 'Folder 1.1' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Folder 1'
      01:53:55 nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Folder 1.1
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/29e7fe14-0207-424a-bf77-c906faffb92d/blobholder:0/File%202.txt","digest":"08f8e0260c64418510cefb2b06eee5cd","creationDate":1386809464022,"canDelete":true,"lastModificationDate":1386809464074,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","folder":false,"name":"File 2.txt","id":"defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d/defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d'])
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Folder 1/Folder 1.1', remote_name=u'Folder 1.1', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"canCreateChild":true,"creationDate":1386809463865,"canDelete":true,"lastModificationDate":1386809463865,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e","folder":true,"name":"Folder 1.2","id":"defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'Folder 1.2', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local folder 'Folder 1.2' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Folder 1'
      01:53:55 nxdrive.synchronizer: DEBUG: Remote recursive scan of the content of Folder 1.2
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:03', '2013-12-12 01:51:03'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetChildren' with cookies [] and JSON payload: '[{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/ba2e36b6-b01d-4988-93ff-f243312c6617/blobholder:0/File%203.txt","digest":"9df62e693988eb4e1e1444ece0578579","creationDate":1386809464092,"canDelete":true,"lastModificationDate":1386809464114,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea","folder":false,"name":"File 3.txt","id":"defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea/defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617","userName":"nuxeoDriveTestUser_user_1"}]'
      01:53:55 nxdrive.model: TRACE: Selecting refs set([u'defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617'])
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Folder 1/Folder 1.2', remote_name=u'Folder 1.2', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/ba2e36b6-b01d-4988-93ff-f243312c6617/blobholder:0/File%203.txt","digest":"9df62e693988eb4e1e1444ece0578579","creationDate":1386809464092,"canDelete":true,"lastModificationDate":1386809464114,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea","folder":false,"name":"File 3.txt","id":"defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea/defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:04', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'File 3.txt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local file 'File 3.txt' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Folder 1/Folder 1.2'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/ba2e36b6-b01d-4988-93ff-f243312c6617/blobholder:0/File%203.txt","digest":"9df62e693988eb4e1e1444ece0578579","creationDate":1386809464092,"canDelete":true,"lastModificationDate":1386809464114,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea","folder":false,"name":"File 3.txt","id":"defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#77d9201a-1f33-423a-9fbd-67737499c5ea/defaultFileSystemItemFactory#default#ba2e36b6-b01d-4988-93ff-f243312c6617","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/ba2e36b6-b01d-4988-93ff-f243312c6617/blobholder:0/File%203.txt' with headers: {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Folder 1/Folder 1.2/File 3.txt', remote_name=u'File 3.txt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/29e7fe14-0207-424a-bf77-c906faffb92d/blobholder:0/File%202.txt","digest":"08f8e0260c64418510cefb2b06eee5cd","creationDate":1386809464022,"canDelete":true,"lastModificationDate":1386809464074,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","folder":false,"name":"File 2.txt","id":"defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d/defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.model: TRACE: Use last known modification time to detect updates: local DB, server = '2013-12-12 01:51:04', '2013-12-12 01:51:04'
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=None, remote_name=u'File 2.txt', local_state=u'unknown', remote_state='created', pair_state='remotely_created'>
      01:53:55 nxdrive.synchronizer: DEBUG: Creating local file 'File 2.txt' in '/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive/Nuxeo Drive Test Workspace/Folder 1/Folder 1.1'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'id': u'defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem with headers {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}, cookies [] and JSON payload '{"params": {"id": "defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.GetFileSystemItem' with cookies [] and JSON payload: '{"digestAlgorithm":"md5","canUpdate":true,"downloadURL":"nxbigfile/default/29e7fe14-0207-424a-bf77-c906faffb92d/blobholder:0/File%202.txt","digest":"08f8e0260c64418510cefb2b06eee5cd","creationDate":1386809464022,"canDelete":true,"lastModificationDate":1386809464074,"canRename":true,"creator":"nuxeoDriveTestUser_user_1","parentId":"defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","folder":false,"name":"File 2.txt","id":"defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d","path":"/org.nuxeo.drive.service.impl.DefaultTopLevelFolderItemFactory#/defaultSyncRootFolderItemFactory#default#9da74aa4-7ab6-45af-b0fa-4812644e21b0/defaultFileSystemItemFactory#default#a42412f5-7c3f-431e-b263-ff4150426d6e/defaultFileSystemItemFactory#default#e366ed9b-f3e3-4be5-8393-95f4c0ddb73d/defaultFileSystemItemFactory#default#29e7fe14-0207-424a-bf77-c906faffb92d","userName":"nuxeoDriveTestUser_user_1"}'
      01:53:55 nxdrive.client.remote_file_system_client: TRACE: Calling 'http://localhost:8080/nuxeo/nxbigfile/default/29e7fe14-0207-424a-bf77-c906faffb92d/blobholder:0/File%202.txt' with headers: {'X-Authentication-Token': '517708ce-0a08-4bcc-ad07-a379abfcdbdb', 'X-Device-Id': u'7911aca062c711e3bdca00219b008ad3', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'X-Client-Version': '1.2-dev'}
      01:53:55 nxdrive.model: TRACE: Updated state for LastKnownState<local_folder=u'/tmp/tmpFiwG6y-nxdrive-tests-user-1/Nuxeo Drive', local_path=u'/Nuxeo Drive Test Workspace/Folder 1/Folder 1.1/File 2.txt', remote_name=u'File 2.txt', local_state='synchronized', remote_state='synchronized', pair_state='synchronized'>
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'query': u"SELECT * FROM Document WHERE ecm:path = '/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1/File 2.txt' AND ecm:currentLifeCycleState != 'deleted' AND ecm:isCheckedInVersion = 0 LIMIT 1"}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Query with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"query": "SELECT * FROM Document WHERE ecm:path = \'/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1/File 2.txt\' AND ecm:currentLifeCycleState != \'deleted\' AND ecm:isCheckedInVersion = 0 LIMIT 1"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Query' with cookies [] and JSON payload: '{"entity-type":"documents","entries":[{"entity-type":"document","repository":"default","uid":"29e7fe14-0207-424a-bf77-c906faffb92d","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1/File 2.txt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"File 2.txt","lastModified":"2013-12-12T00:51:04.07Z","properties":{"uid:uid":null,"uid:minor_version":"0","uid:major_version":"0","dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:04.02Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:04.07Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"File 2.txt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"thumb:thumbnail":{"name":"2c90aa328765cd6a89c910f1bfe18146","mime-type":"application/octet-stream","encoding":null,"digest":"2c90aa328765cd6a89c910f1bfe18146","length":"278","data":"files/29e7fe14-0207-424a-bf77-c906faffb92d?path=%2Fthumb%3Athumbnail"},"common:icon":"/icons/text.png","common:icon-expanded":null,"common:size":"3","file:content":{"name":"File 2.txt","mime-type":"text/plain","encoding":null,"digest":"08f8e0260c64418510cefb2b06eee5cd","length":"3","data":"files/29e7fe14-0207-424a-bf77-c906faffb92d?path=%2Fcontent"},"file:filename":null,"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","Versionable","Publishable","HasRelatedText","Thumbnail"],"changeToken":"1386809464074","contextParameters":{}}]}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1/File 2.txt'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"value": "/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1/File 2.txt"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"29e7fe14-0207-424a-bf77-c906faffb92d","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1/File 2.txt","type":"File","state":"project","versionLabel":"0.0","isCheckedOut":true,"title":"File 2.txt","lastModified":"2013-12-12T00:51:04.07Z","properties":{"uid:uid":null,"uid:minor_version":"0","uid:major_version":"0","dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:04.02Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:04.07Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"File 2.txt","dc:lastContributor":"nuxeoDriveTestUser_user_1","files:files":[],"thumb:thumbnail":{"name":"2c90aa328765cd6a89c910f1bfe18146","mime-type":"application/octet-stream","encoding":null,"digest":"2c90aa328765cd6a89c910f1bfe18146","length":"278","data":"files/29e7fe14-0207-424a-bf77-c906faffb92d?path=%2Fthumb%3Athumbnail"},"common:icon":"/icons/text.png","common:icon-expanded":null,"common:size":"3","file:content":{"name":"File 2.txt","mime-type":"text/plain","encoding":null,"digest":"08f8e0260c64418510cefb2b06eee5cd","length":"3","data":"files/29e7fe14-0207-424a-bf77-c906faffb92d?path=%2Fcontent"},"file:filename":null,"relatedtext:relatedtextresources":[]},"facets":["Downloadable","Commentable","Versionable","Publishable","HasRelatedText","Thumbnail"],"changeToken":"1386809464074","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"value": "/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"e366ed9b-f3e3-4be5-8393-95f4c0ddb73d","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Folder 1.1","lastModified":"2013-12-12T00:51:03.84Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:03.84Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:03.84Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Folder 1.1","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1386809463844","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 4, 'X-Client-Version': '1.2-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 4, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1386809468.28_993600129', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'File%202.txt'} and cookies [] for file /tmp/tmpQtCkm8-nxdrive-uploads/tmp_X55AW-nxdrive-file-to-upload
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies [] and JSON payload: '{"uploaded":"true","batchId":"1386809468.28_993600129"}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1386809468.28_993600129', 'document': u'/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1/File 2.txt', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"params": {"batchId": "1386809468.28_993600129", "document": "/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 1/Folder 1.1/File 2.txt", "fileIdx": "0", "operationId": "Blob.Attach"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] and content-type: 'text/plain'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 2', 'params': {'value': 'delete'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.SetLifeCycle with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 2", "params": {"value": "delete"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.SetLifeCycle' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"73455c7c-edaf-4db3-bd39-77f8c711549a","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 2","type":"Folder","state":"deleted","versionLabel":"","isCheckedOut":true,"title":"Folder 2","lastModified":"2013-12-12T00:51:08.29Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:03.88Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:08.29Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Folder 2","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1386809468298","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:9da74aa4-7ab6-45af-b0fa-4812644e21b0', 'params': {'type': 'Folder', 'name': 'Folder 3', 'properties': 'dc:title=Folder 3'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:9da74aa4-7ab6-45af-b0fa-4812644e21b0", "params": {"type": "Folder", "name": "Folder 3", "properties": "dc:title=Folder 3"}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies [] and JSON payload: '{"entity-type":"document","repository":"default","uid":"20ed6f20-00f6-46ba-bb74-99414fdf5c32","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Folder 3","type":"Folder","state":"project","versionLabel":"","isCheckedOut":true,"title":"Folder 3","lastModified":"2013-12-12T00:51:08.31Z","properties":{"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2013-12-12T00:51:08.31Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2013-12-12T00:51:08.31Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Folder 3","dc:lastContributor":"nuxeoDriveTestUser_user_1","common:icon":"/icons/folder.gif","common:icon-expanded":null,"common:size":null},"facets":["Folderish"],"changeToken":"1386809468314","contextParameters":{}}'
      01:53:55 nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:20ed6f20-00f6-46ba-bb74-99414fdf5c32', 'params': {'type': 'File', 'name': 'File 6.txt', 'properties': 'dc:title=File 6.txt'}}
      01:53:55 nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.2-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTo4OTMwMTA='}, cookies [] and JSON payload '{"input": "doc:20ed6f20-00f6-46ba-bb74-99414fdf5c32", "params": {"type": "File", "name": "File 6.txt", "properties": "dc:title=File 6.txt"}}'
      01:53:55 nxdrive.client.base_automation_client: DEBUG: Failed to execute operation: Document.Create
      01:53:55 nxdrive.client.base_automation_client: DEBUG: org.nuxeo.ecm.core.api.ConcurrentUpdateException: Failed to save session
      01:53:55 	at org.nuxeo.ecm.core.api.AbstractSession.save(AbstractSession.java:1783)
      01:53:55 	at sun.reflect.GeneratedMethodAccessor58.invoke(Unknown Source)
      01:53:55 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      01:53:55 	at java.lang.reflect.Method.invoke(Method.java:606)
      01:53:55 	at org.nuxeo.ecm.core.api.TransactionalCoreSessionWrapper.invoke(TransactionalCoreSessionWrapper.java:136)
      01:53:55 	at com.sun.proxy.$Proxy88.save(Unknown Source)
      01:53:55 	at org.nuxeo.ecm.automation.core.impl.OperationServiceImpl.run(OperationServiceImpl.java:173)
      01:53:55 	at org.nuxeo.ecm.automation.core.impl.OperationServiceImpl.run(OperationServiceImpl.java:116)
      01:53:55 	at org.nuxeo.ecm.automation.server.jaxrs.OperationResource.execute(OperationResource.java:46)
      01:53:55 	at org.nuxeo.ecm.automation.server.jaxrs.ExecutableResource.doPost(ExecutableResource.java:56)
      01:53:55 	at sun.reflect.GeneratedMethodAccessor179.invoke(Unknown Source)
      01:53:55 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      01:53:55 	at java.lang.reflect.Method.invoke(Method.java:606)
      01:53:55 	at com.sun.jersey.spi.container.JavaMethodInvokerFactory$1.invoke(JavaMethodInvokerFactory.java:60)
      01:53:55 	at com.sun.jersey.server.impl.model.method.dispatch.AbstractResourceMethodDispatchProvider$ObjectOutInvoker._dispatch(AbstractResourceMethodDispatchProvider.java:258)
      01:53:55 	at com.sun.jersey.server.impl.model.method.dispatch.ResourceJavaMethodDispatcher.dispatch(ResourceJavaMethodDispatcher.java:75)
      01:53:55 	at com.sun.jersey.server.impl.uri.rules.HttpMethodRule.accept(HttpMethodRule.java:302)
      01:53:55 	at com.sun.jersey.server.impl.uri.rules.SubLocatorRule.accept(SubLocatorRule.java:137)
      01:53:55 	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
      01:53:55 	at com.sun.jersey.server.impl.uri.rules.ResourceClassRule.accept(ResourceClassRule.java:108)
      01:53:55 	at com.sun.jersey.server.impl.uri.rules.RightHandPathRule.accept(RightHandPathRule.java:147)
      01:53:55 	at com.sun.jersey.server.impl.uri.rules.RootResourceClassesRule.accept(RootResourceClassesRule.java:84)
      01:53:55 	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1511)
      01:53:55 	at com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1442)
      01:53:55 	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1391)
      01:53:55 	at com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1381)
      01:53:55 	at com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:416)
      01:53:55 	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:538)
      01:53:55 	at com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:716)
      01:53:55 	at org.nuxeo.ecm.webengine.app.jersey.WebEngineServlet.containerService(WebEngineServlet.java:177)
      01:53:55 	at org.nuxeo.ecm.webengine.app.jersey.WebEngineServlet.service(WebEngineServlet.java:152)
      01:53:55 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:728)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:305)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.webengine.jaxrs.session.SessionCleanupFilter.run(SessionCleanupFilter.java:45)
      01:53:55 	at org.nuxeo.ecm.webengine.jaxrs.HttpFilter.doFilter(HttpFilter.java:43)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.webengine.app.WebEngineFilter.doFilter(WebEngineFilter.java:92)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.webengine.jaxrs.context.RequestContextFilter.run(RequestContextFilter.java:42)
      01:53:55 	at org.nuxeo.ecm.webengine.jaxrs.HttpFilter.doFilter(HttpFilter.java:43)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.core.management.jtajca.internal.Log4jWebFilter.doFilter(Log4jWebFilter.java:64)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.platform.ui.web.rest.FancyURLFilter.doFilter(FancyURLFilter.java:129)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.webdav.service.WIRequestFilter.doFilter(WIRequestFilter.java:61)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.platform.web.common.requestcontroller.filter.NuxeoRequestControllerFilter.doFilter(NuxeoRequestControllerFilter.java:145)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doFilterInternal(NuxeoAuthenticationFilter.java:614)
      01:53:55 	at org.nuxeo.ecm.platform.ui.web.auth.NuxeoAuthenticationFilter.doFilter(NuxeoAuthenticationFilter.java:406)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.platform.web.common.requestcontroller.filter.NuxeoCorsFilter.doFilter(NuxeoCorsFilter.java:51)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.platform.web.common.exceptionhandling.NuxeoExceptionFilter.doFilter(NuxeoExceptionFilter.java:79)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.nuxeo.ecm.platform.web.common.encoding.NuxeoEncodingFilter.doFilter(NuxeoEncodingFilter.java:69)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
      01:53:55 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
      01:53:55 	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:222)
      01:53:55 	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:123)
      01:53:55 	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:502)
      01:53:55 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:171)
      01:53:55 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:99)
      01:53:55 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
      01:53:55 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:408)
      01:53:55 	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1023)
      01:53:55 	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:589)
      01:53:55 	at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:310)
      01:53:55 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
      01:53:55 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
      01:53:55 	at java.lang.Thread.run(Thread.java:724)
      01:53:55 Caused by: org.nuxeo.ecm.core.api.ConcurrentUpdateDocumentException: org.nuxeo.ecm.core.storage.ConcurrentUpdateStorageException: org.h2.jdbc.JdbcBatchUpdateException: Deadlock detected. The current transaction was rolled back. Details: 
      01:53:55 Session #9 (user: SA) is waiting to lock PUBLIC.MISC while locking PUBLIC.NXP_LOGS (exclusive), PUBLIC.NXP_LOGS_EXTINFO (exclusive), PUBLIC.NXP_LOGS_MAPEXTINFOS (exclusive), PUBLIC.DUBLINCORE (exclusive).
      01:53:55 Session #7 (user: SA) is waiting to lock PUBLIC.DUBLINCORE while locking , PUBLIC.HIERARCHY (exclusive), PUBLIC.COMMON (exclusive), PUBLIC.MISC (exclusive), PUBLIC.FULLTEXT (exclusive), PUBLIC.DC_CONTRIBUTORS (exclusive).; SQL statement:
      01:53:55 INSERT INTO "DUBLINCORE" ("ID", "CREATOR", "SOURCE", "NATURE", "CREATED", "DESCRIPTION", "RIGHTS", "PUBLISHER", "VALID", "FORMAT", "ISSUED", "MODIFIED", "LANGUAGE", "COVERAGE", "EXPIRED", "LASTCONTRIBUTOR", "TITLE") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [40001-114]
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.coremodel.SQLSession.save(SQLSession.java:159)
      01:53:55 	at org.nuxeo.ecm.core.api.AbstractSession.save(AbstractSession.java:1779)
      01:53:55 	... 82 more
      01:53:55 Caused by: org.nuxeo.ecm.core.storage.ConcurrentUpdateStorageException: org.h2.jdbc.JdbcBatchUpdateException: Deadlock detected. The current transaction was rolled back. Details: 
      01:53:55 Session #9 (user: SA) is waiting to lock PUBLIC.MISC while locking PUBLIC.NXP_LOGS (exclusive), PUBLIC.NXP_LOGS_EXTINFO (exclusive), PUBLIC.NXP_LOGS_MAPEXTINFOS (exclusive), PUBLIC.DUBLINCORE (exclusive).
      01:53:55 Session #7 (user: SA) is waiting to lock PUBLIC.DUBLINCORE while locking , PUBLIC.HIERARCHY (exclusive), PUBLIC.COMMON (exclusive), PUBLIC.MISC (exclusive), PUBLIC.FULLTEXT (exclusive), PUBLIC.DC_CONTRIBUTORS (exclusive).; SQL statement:
      01:53:55 INSERT INTO "DUBLINCORE" ("ID", "CREATOR", "SOURCE", "NATURE", "CREATED", "DESCRIPTION", "RIGHTS", "PUBLISHER", "VALID", "FORMAT", "ISSUED", "MODIFIED", "LANGUAGE", "COVERAGE", "EXPIRED", "LASTCONTRIBUTOR", "TITLE") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [40001-114]
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCConnection.checkConcurrentUpdate(JDBCConnection.java:322)
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.insertSimpleRows(JDBCRowMapper.java:605)
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.writeCreates(JDBCRowMapper.java:502)
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.write(JDBCRowMapper.java:472)
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.SoftRefCachingRowMapper.write(SoftRefCachingRowMapper.java:427)
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.SessionImpl.flush(SessionImpl.java:388)
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.SessionImpl.flushAndScheduleWork(SessionImpl.java:364)
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.SessionImpl.save(SessionImpl.java:343)
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.ra.ConnectionImpl.save(ConnectionImpl.java:184)
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.coremodel.SQLSession.save(SQLSession.java:157)
      01:53:55 	... 83 more
      01:53:55 Caused by: org.h2.jdbc.JdbcBatchUpdateException: Deadlock detected. The current transaction was rolled back. Details: 
      01:53:55 Session #9 (user: SA) is waiting to lock PUBLIC.MISC while locking PUBLIC.NXP_LOGS (exclusive), PUBLIC.NXP_LOGS_EXTINFO (exclusive), PUBLIC.NXP_LOGS_MAPEXTINFOS (exclusive), PUBLIC.DUBLINCORE (exclusive).
      01:53:55 Session #7 (user: SA) is waiting to lock PUBLIC.DUBLINCORE while locking , PUBLIC.HIERARCHY (exclusive), PUBLIC.COMMON (exclusive), PUBLIC.MISC (exclusive), PUBLIC.FULLTEXT (exclusive), PUBLIC.DC_CONTRIBUTORS (exclusive).; SQL statement:
      01:53:55 INSERT INTO "DUBLINCORE" ("ID", "CREATOR", "SOURCE", "NATURE", "CREATED", "DESCRIPTION", "RIGHTS", "PUBLISHER", "VALID", "FORMAT", "ISSUED", "MODIFIED", "LANGUAGE", "COVERAGE", "EXPIRED", "LASTCONTRIBUTOR", "TITLE") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [40001-114]
      01:53:55 	at org.h2.jdbc.JdbcPreparedStatement.executeBatch(JdbcPreparedStatement.java:1067)
      01:53:55 	at org.apache.tomcat.dbcp.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297)
      01:53:55 	at org.apache.tomcat.dbcp.dbcp.DelegatingStatement.executeBatch(DelegatingStatement.java:297)
      01:53:55 	at org.nuxeo.ecm.core.storage.sql.jdbc.JDBCRowMapper.insertSimpleRows(JDBCRowMapper.java:590)
      01:53:55 	... 91 more
      01:53:55 Caused by: org.h2.jdbc.JdbcSQLException: Deadlock detected. The current transaction was rolled back. Details: 
      01:53:55 Session #9 (user: SA) is waiting to lock PUBLIC.MISC while locking PUBLIC.NXP_LOGS (exclusive), PUBLIC.NXP_LOGS_EXTINFO (exclusive), PUBLIC.NXP_LOGS_MAPEXTINFOS (exclusive), PUBLIC.DUBLINCORE (exclusive).
      01:53:55 Session #7 (user: SA) is waiting to lock PUBLIC.DUBLINCORE while locking , PUBLIC.HIERARCHY (exclusive), PUBLIC.COMMON (exclusive), PUBLIC.MISC (exclusive), PUBLIC.FULLTEXT (exclusive), PUBLIC.DC_CONTRIBUTORS (exclusive).; SQL statement:
      01:53:55 INSERT INTO "DUBLINCORE" ("ID", "CREATOR", "SOURCE", "NATURE", "CREATED", "DESCRIPTION", "RIGHTS", "PUBLISHER", "VALID", "FORMAT", "ISSUED", "MODIFIED", "LANGUAGE", "COVERAGE", "EXPIRED", "LASTCONTRIBUTOR", "TITLE") VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) [40001-114]
      01:53:55 	at org.h2.message.Message.getSQLException(Message.java:105)
      01:53:55 	at org.h2.message.Message.getSQLException(Message.java:116)
      01:53:55 	at org.h2.message.Message.getSQLException(Message.java:75)
      01:53:55 	at org.h2.table.TableData.doLock(TableData.java:426)
      01:53:55 	at org.h2.table.TableData.lock(TableData.java:373)
      01:53:55 	at org.h2.command.dml.Insert.update(Insert.java:100)
      01:53:55 	at org.h2.command.CommandContainer.update(CommandContainer.java:72)
      01:53:55 	at org.h2.command.Command.executeUpdate(Command.java:208)
      01:53:55 	at org.h2.jdbc.JdbcPreparedStatement.executeUpdateInternal(JdbcPreparedStatement.java:139)
      01:53:55 	at org.h2.jdbc.JdbcPreparedStatement.executeBatch(JdbcPreparedStatement.java:1050)
      01:53:55 	... 94 more
      01:53:55 Traceback (most recent call last):
      01:53:55   File "/home/hudson/tmp/workspace/IT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive/client/base_automation_client.py", line 288, in execute
      01:53:55     resp = self.opener.open(req, timeout=timeout)
      01:53:55   File "/usr/lib/python2.7/urllib2.py", line 406, in open
      01:53:55     response = meth(req, response)
      01:53:55   File "/usr/lib/python2.7/urllib2.py", line 519, in http_response
      01:53:55     'http', request, response, code, msg, hdrs)
      01:53:55   File "/usr/lib/python2.7/urllib2.py", line 444, in error
      01:53:55     return self._call_chain(*args)
      01:53:55   File "/usr/lib/python2.7/urllib2.py", line 378, in _call_chain
      01:53:55     result = func(*args)
      01:53:55   File "/usr/lib/python2.7/urllib2.py", line 527, in http_error_default
      01:53:55     raise HTTPError(req.get_full_url(), code, msg, hdrs, fp)
      01:53:55 HTTPError: HTTP Error 500: Internal Server Error
      01:53:55 --------------------- >> end captured logging << ---------------------
      

        Attachments

          Issue Links

            Activity

              People

              • Votes:
                0 Vote for this issue
                Watchers:
                2 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: