Random failure at line 111, in test_make_documents

19:08:13 [INFO]      [exec] ======================================================================
19:08:13 [INFO]      [exec] FAIL: test_make_documents (nxdrive.tests.test_integration_remote_document_client.TestIntegrationRemoteDocumentClient)
19:08:13 [INFO]      [exec] ----------------------------------------------------------------------
19:08:13 [INFO]      [exec] Traceback (most recent call last):
19:08:13 [INFO]      [exec]   File "/home/hudson/tmp/workspace/FT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive/tests/test_integration_remote_document_client.py", line 111, in test_make_documents
19:08:13 [INFO]      [exec]     self.SOME_TEXT_CONTENT)
19:08:13 [INFO]      [exec] AssertionError: '' != 'Some text content.'
19:08:13 [INFO]      [exec] -------------------- >> begin captured logging << --------------------
19:08:13 [INFO]      [exec] nxdrive.controller: INFO: nxdrive installed in '/home/hudson/tmp/workspace/FT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive'
19:08:13 [INFO]      [exec] nxdrive.controller: INFO: nxdrive configured in '/tmp/tmpdZHzLW-nxdrive-tests-user-1/nuxeo-drive-conf'
19:08:13 [INFO]      [exec] alembic.migration: INFO: Context impl SQLiteImpl.
19:08:13 [INFO]      [exec] alembic.migration: INFO: Will assume non-transactional DDL.
19:08:13 [INFO]      [exec] nxdrive.migration: DEBUG: Checking if SQLite database migration is needed.
19:08:13 [INFO]      [exec] nxdrive.migration: DEBUG: Head Alembic revision: 2f126b5f61a6
19:08:13 [INFO]      [exec] nxdrive.migration: DEBUG: Alembic is not initialized, setting current revision to head revision: 2f126b5f61a6
19:08:13 [INFO]      [exec] nxdrive.migration: DEBUG: Current Alembic revision: 2f126b5f61a6
19:08:13 [INFO]      [exec] nxdrive.migration: DEBUG: No migration to process as current Alembic revision in SQLite database is already the head revision.
19:08:13 [INFO]      [exec] nxdrive.model: DEBUG: Set client version to 1.3-dev
19:08:13 [INFO]      [exec] nxdrive.controller: INFO: nxdrive installed in '/home/hudson/tmp/workspace/FT-nuxeo-drive-master-linux/nuxeo-drive-client/nxdrive'
19:08:13 [INFO]      [exec] nxdrive.controller: INFO: nxdrive configured in '/tmp/tmpp9UqwN-nxdrive-tests-user-2/nuxeo-drive-conf'
19:08:13 [INFO]      [exec] alembic.migration: INFO: Context impl SQLiteImpl.
19:08:13 [INFO]      [exec] alembic.migration: INFO: Will assume non-transactional DDL.
19:08:13 [INFO]      [exec] nxdrive.migration: DEBUG: Checking if SQLite database migration is needed.
19:08:13 [INFO]      [exec] nxdrive.migration: DEBUG: Head Alembic revision: 2f126b5f61a6
19:08:13 [INFO]      [exec] nxdrive.migration: DEBUG: Alembic is not initialized, setting current revision to head revision: 2f126b5f61a6
19:08:13 [INFO]      [exec] nxdrive.migration: DEBUG: Current Alembic revision: 2f126b5f61a6
19:08:13 [INFO]      [exec] nxdrive.migration: DEBUG: No migration to process as current Alembic revision in SQLite database is already the head revision.
19:08:13 [INFO]      [exec] nxdrive.model: DEBUG: Set client version to 1.3-dev
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-administrator-device', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'} and cookies []
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/'}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"value": "/"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"88e9ba13-9805-4af8-a311-97faccaf4a79","path":"/","type":"Root","state":null,"parentRef":"/","versionLabel":"","isCheckedOut":true,"title":"88e9ba13-9805-4af8-a311-97faccaf4a79","properties":{"dc:creator":null,"dc:source":null,"dc:nature":null,"dc:contributors":[],"dc:created":null,"dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":null,"dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":null,"dc:lastContributor":null,"common:icon":null,"common:icon-expanded":null,"common:size":null},"facets":["Folderish","NotCollectionMember"],"changeToken":null,"contextParameters":{}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'userNames': 'user_1, user_2', 'permission': 'ReadWrite'}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"userNames": "user_1, user_2", "permission": "ReadWrite"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/NuxeoDrive.SetupIntegrationTests' with cookies [] has content-type 'text/plain'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/default-domain/workspaces/nuxeo-drive-test-workspace'}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-administrator-device', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': 'Administrator', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic QWRtaW5pc3RyYXRvcjpBZG1pbmlzdHJhdG9y'}, cookies [] and JSON payload '{"params": {"value": "/default-domain/workspaces/nuxeo-drive-test-workspace"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"3055bf55-cc55-4887-8ffe-d8d3a6ea898d","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-12-05T17:59:14.81Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:nature":null,"dc:contributors":["Administrator"],"dc:created":"2014-12-05T17:59:14.81Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-05T17:59:14.81Z","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":"1417802354815","contextParameters":{}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='} and cookies []
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe'}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"params": {"value": "f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"3055bf55-cc55-4887-8ffe-d8d3a6ea898d","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-12-05T17:59:14.81Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:nature":null,"dc:contributors":["Administrator"],"dc:created":"2014-12-05T17:59:14.81Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-05T17:59:14.81Z","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":"1417802354815","contextParameters":{}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-2', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo1MDkzMGQ='} and cookies []
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe'}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-2', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo1MDkzMGQ='}, cookies [] and JSON payload '{"params": {"value": "f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"3055bf55-cc55-4887-8ffe-d8d3a6ea898d","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-12-05T17:59:14.81Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:nature":null,"dc:contributors":["Administrator"],"dc:created":"2014-12-05T17:59:14.81Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-05T17:59:14.81Z","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":"1417802354815","contextParameters":{}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='} and cookies []
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/ with headers {'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-2', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_2', 'Cache-Control': 'no-cache', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMjo1MDkzMGQ='} and cookies []
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe', 'params': {'type': 'File', 'name': 'Document 1.txt', 'properties': 'dc:title=Document 1.txt'}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"input": "doc:f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe", "params": {"type": "File", "name": "Document 1.txt", "properties": "dc:title=Document 1.txt"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies []: '{"entity-type":"document","repository":"default","uid":"c6e55161-0ab1-4211-9e34-9410d187ee0d","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Document 1.txt","type":"File","state":"project","parentRef":"f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe","versionLabel":"0.0","isCheckedOut":true,"title":"Document 1.txt","lastModified":"2014-12-05T17:59:14.98Z","properties":{"uid:uid":null,"uid:minor_version":0,"uid:major_version":0,"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2014-12-05T17:59:14.98Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-05T17:59:14.98Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Document 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":"1417802354984","contextParameters":{}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'query': u"SELECT * FROM Document WHERE ecm:uuid = 'c6e55161-0ab1-4211-9e34-9410d187ee0d' AND ecm:currentLifeCycleState != 'deleted' AND ecm:isCheckedInVersion = 0 LIMIT 1"}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Query with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"params": {"query": "SELECT * FROM Document WHERE ecm:uuid = \'c6e55161-0ab1-4211-9e34-9410d187ee0d\' AND ecm:currentLifeCycleState != \'deleted\' AND ecm:isCheckedInVersion = 0 LIMIT 1"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Query' with cookies []: '{"entity-type":"documents","isPaginable":true,"resultsCount":1,"pageSize":0,"maxPageSize":1000,"currentPageSize":1,"currentPageIndex":0,"numberOfPages":1,"isPreviousPageAvailable":false,"isNextPageAvailable":false,"isLastPageAvailable":false,"isSortable":true,"hasError":false,"errorMessage":null,"totalSize":1,"pageIndex":0,"pageCount":1,"entries":[{"entity-type":"document","repository":"default","uid":"c6e55161-0ab1-4211-9e34-9410d187ee0d","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Document 1.txt","type":"File","state":"project","parentRef":"f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe","versionLabel":"0.0","isCheckedOut":true,"title":"Document 1.txt","lastModified":"2014-12-05T17:59:14.98Z","properties":{"uid:uid":null,"uid:minor_version":0,"uid:major_version":0,"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2014-12-05T17:59:14.98Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-05T17:59:14.98Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Document 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":"1417802354984","contextParameters":{"documentURL":"/nuxeo/nxdoc/default/c6e55161-0ab1-4211-9e34-9410d187ee0d/view_documents"}}]}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:c6e55161-0ab1-4211-9e34-9410d187ee0d', 'params': {}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Blob.Get with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"input": "doc:c6e55161-0ab1-4211-9e34-9410d187ee0d", "params": {}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Blob.Get' with cookies [] has content-type 'text/plain'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'query': u"SELECT * FROM Document WHERE ecm:uuid = 'c6e55161-0ab1-4211-9e34-9410d187ee0d' AND ecm:currentLifeCycleState != 'deleted' AND ecm:isCheckedInVersion = 0 LIMIT 1"}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Query with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"params": {"query": "SELECT * FROM Document WHERE ecm:uuid = \'c6e55161-0ab1-4211-9e34-9410d187ee0d\' AND ecm:currentLifeCycleState != \'deleted\' AND ecm:isCheckedInVersion = 0 LIMIT 1"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Query' with cookies []: '{"entity-type":"documents","isPaginable":true,"resultsCount":1,"pageSize":0,"maxPageSize":1000,"currentPageSize":1,"currentPageIndex":0,"numberOfPages":1,"isPreviousPageAvailable":false,"isNextPageAvailable":false,"isLastPageAvailable":false,"isSortable":true,"hasError":false,"errorMessage":null,"totalSize":1,"pageIndex":0,"pageCount":1,"entries":[{"entity-type":"document","repository":"default","uid":"c6e55161-0ab1-4211-9e34-9410d187ee0d","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Document 1.txt","type":"File","state":"project","parentRef":"f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe","versionLabel":"0.0","isCheckedOut":true,"title":"Document 1.txt","lastModified":"2014-12-05T17:59:14.98Z","properties":{"uid:uid":null,"uid:minor_version":0,"uid:major_version":0,"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2014-12-05T17:59:14.98Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-05T17:59:14.98Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Document 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":"1417802354984","contextParameters":{"documentURL":"/nuxeo/nxdoc/default/c6e55161-0ab1-4211-9e34-9410d187ee0d/view_documents"}}]}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'c6e55161-0ab1-4211-9e34-9410d187ee0d'}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"params": {"value": "c6e55161-0ab1-4211-9e34-9410d187ee0d"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"c6e55161-0ab1-4211-9e34-9410d187ee0d","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Document 1.txt","type":"File","state":"project","parentRef":"f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe","versionLabel":"0.0","isCheckedOut":true,"title":"Document 1.txt","lastModified":"2014-12-05T17:59:14.98Z","properties":{"uid:uid":null,"uid:minor_version":0,"uid:major_version":0,"dc:creator":"nuxeoDriveTestUser_user_1","dc:source":null,"dc:nature":null,"dc:contributors":["nuxeoDriveTestUser_user_1"],"dc:created":"2014-12-05T17:59:14.98Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-05T17:59:14.98Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Document 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":"1417802354984","contextParameters":{}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'value': u'/default-domain/workspaces/nuxeo-drive-test-workspace'}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Fetch with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"params": {"value": "/default-domain/workspaces/nuxeo-drive-test-workspace"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Fetch' with cookies []: '{"entity-type":"document","repository":"default","uid":"f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe","path":"/default-domain/workspaces/nuxeo-drive-test-workspace","type":"Workspace","state":"project","parentRef":"3055bf55-cc55-4887-8ffe-d8d3a6ea898d","versionLabel":"","isCheckedOut":true,"title":"Nuxeo Drive Test Workspace","lastModified":"2014-12-05T17:59:14.81Z","properties":{"dc:creator":"Administrator","dc:source":null,"dc:nature":null,"dc:contributors":["Administrator"],"dc:created":"2014-12-05T17:59:14.81Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-05T17:59:14.81Z","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":"1417802354815","contextParameters":{}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe', 'params': {'type': 'File', 'name': 'Document 2.txt', 'properties': 'dc:title=Document 2.txt'}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Create with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"input": "doc:f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe", "params": {"type": "File", "name": "Document 2.txt", "properties": "dc:title=Document 2.txt"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Create' with cookies []: '{"entity-type":"document","repository":"default","uid":"2dd4ecf4-5be0-4ca7-92e9-e996b9b20447","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Document 2.txt","type":"File","state":"project","parentRef":"f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe","versionLabel":"0.0","isCheckedOut":true,"title":"Document 2.txt","lastModified":"2014-12-05T17:59:15.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":"2014-12-05T17:59:15.09Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-05T17:59:15.09Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Document 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":"1417802355094","contextParameters":{}}'
19:08:13 [INFO]      [exec] nxdrive.utils: TRACE: Guessed mime type 'text/plain' for 'Document 2.txt'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Using file system block size for the streaming upload buffer: 4096 bytes
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/upload with headers {'Content-Length': 18, 'X-Client-Version': '1.3-dev', 'X-Device-Id': u'nxdrive-test-device-1', 'X-File-Type': 'text/plain', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-File-Size': 18, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY=', 'Cache-Control': 'no-cache', 'X-Batch-Id': '1417802355.12_98341309', 'X-File-Idx': 0, 'Content-Type': 'application/octet-stream', 'X-Application-Name': 'Nuxeo Drive', 'X-File-Name': 'Document%202.txt'} and cookies [] for file /tmp/tmpIQP8g2-nxdrive-uploads/tmplBr_JL-nxdrive-file-to-upload
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/upload' with cookies []: '{"uploaded":"true","batchId":"1417802355.12_98341309"}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Using 300 seconds [max(300, 2 * upload time=0)] as Nuxeo transaction timeout for batch execution of Blob.Attach with file /tmp/tmpIQP8g2-nxdrive-uploads/tmplBr_JL-nxdrive-file-to-upload
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'batchId': '1417802355.12_98341309', 'document': u'2dd4ecf4-5be0-4ca7-92e9-e996b9b20447', 'fileIdx': '0', 'operationId': 'Blob.Attach'}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/batch/execute with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'X-Application-Name': 'Nuxeo Drive', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'Nuxeo-Transaction-Timeout': 300, 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"params": {"batchId": "1417802355.12_98341309", "document": "2dd4ecf4-5be0-4ca7-92e9-e996b9b20447", "fileIdx": "0", "operationId": "Blob.Attach"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/batch/execute' with cookies [] has content-type 'text/plain'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'params': {'query': u"SELECT * FROM Document WHERE ecm:uuid = '2dd4ecf4-5be0-4ca7-92e9-e996b9b20447' AND ecm:currentLifeCycleState != 'deleted' AND ecm:isCheckedInVersion = 0 LIMIT 1"}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Document.Query with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"params": {"query": "SELECT * FROM Document WHERE ecm:uuid = \'2dd4ecf4-5be0-4ca7-92e9-e996b9b20447\' AND ecm:currentLifeCycleState != \'deleted\' AND ecm:isCheckedInVersion = 0 LIMIT 1"}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Document.Query' with cookies []: '{"entity-type":"documents","isPaginable":true,"resultsCount":1,"pageSize":0,"maxPageSize":1000,"currentPageSize":1,"currentPageIndex":0,"numberOfPages":1,"isPreviousPageAvailable":false,"isNextPageAvailable":false,"isLastPageAvailable":false,"isSortable":true,"hasError":false,"errorMessage":null,"totalSize":1,"pageIndex":0,"pageCount":1,"entries":[{"entity-type":"document","repository":"default","uid":"2dd4ecf4-5be0-4ca7-92e9-e996b9b20447","path":"/default-domain/workspaces/nuxeo-drive-test-workspace/Document 2.txt","type":"File","state":"project","parentRef":"f81f7ca2-fb0e-4104-b27c-5d08bd0c4dfe","versionLabel":"0.0","isCheckedOut":true,"title":"Document 2.txt","lastModified":"2014-12-05T17:59:15.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":"2014-12-05T17:59:15.09Z","dc:description":null,"dc:rights":null,"dc:subjects":[],"dc:publisher":null,"dc:valid":null,"dc:format":null,"dc:issued":null,"dc:modified":"2014-12-05T17:59:15.09Z","dc:expired":null,"dc:coverage":null,"dc:language":null,"dc:title":"Document 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":"1417802355094","contextParameters":{"documentURL":"/nuxeo/nxdoc/default/2dd4ecf4-5be0-4ca7-92e9-e996b9b20447/view_documents"}}]}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Dumping JSON structure: {'input': u'doc:2dd4ecf4-5be0-4ca7-92e9-e996b9b20447', 'params': {}}
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Calling http://localhost:8080/nuxeo/site/automation/Blob.Get with headers {'X-Client-Version': '1.3-dev', 'X-NXDocumentProperties': '*', 'X-Device-Id': u'nxdrive-test-device-1', 'Accept': 'application/json+nxentity, */*', 'User-Agent': 'Nuxeo Drive/1.3-dev', 'X-User-Id': u'nuxeoDriveTestUser_user_1', 'Cache-Control': 'no-cache', 'Content-Type': 'application/json+nxrequest', 'X-Application-Name': 'Nuxeo Drive', 'Authorization': 'Basic bnV4ZW9Ecml2ZVRlc3RVc2VyX3VzZXJfMTplY2U2ZmY='}, cookies [] and JSON payload '{"input": "doc:2dd4ecf4-5be0-4ca7-92e9-e996b9b20447", "params": {}}'
19:08:13 [INFO]      [exec] nxdrive.client.base_automation_client: TRACE: Response for 'http://localhost:8080/nuxeo/site/automation/Blob.Get' with cookies [] has content-type 'text/plain'
19:08:13 [INFO]      [exec] --------------------- >> end captured logging << ---------------------